search

awslabs / amazon-kinesis-video-streams-producer-sdk-cpp

Amazon Kinesis Video Streams Producer SDK for C++ is for developers to install and customize for their connected camera and other devices to securely stream video, audio, and time-encoded data to Kinesis Video Streams.
Apache License 2.0
373 stars 334 forks source link

Unable to get RTSP streaming with H 265 Video Encoding with error "Pad link failed" #431

Closed dvsantana closed 4 years ago

dvsantana commented 4 years ago

I'm using the producer library in a Raspberry Pi 3 to stream from RTSP source.

I tried using the sample multistream app (kinesis_video_gstreamer_sample_multistream_app) to send a H265 video source to AWS KVS.

When I try to send the stream with H265, 1080p, VBR, and 15fps, I get the message "New RTSP source found: / Source Link FAILED" error twice and no information about the streams. It sends the Source Link FAILED from two different sources, as if it tries to connect twice.

However, when I send the stream with H 264, 1080p, VBR, and 15fps, I get "New RTSP source found: / Source linked", and right after: "New RTSP source found: / Source Link FAILED", even though I am only working with one stream. Still, this way, the stream still gets sent to AWS and can be seen on the AWS Management Console.

Then, I tried using the sample app (kinesis_video_gstreamer_sample_app), to see if there was any other information on the error, saw the following error and tried the fix from issue #130 .

"Pad link failed
Error received from element udpsrc1: Internal data stream error."

I changed the kinesis-video-gst-demo/kinesis_video_gstreamer_sample_app.cpp and ran the ./min-install-script:

#include <gst/gst.h>
#include <gst/app/gstappsink.h>
#include <string.h>
#include <gst/rtsp/gstrtsptransport.h>
#include <chrono>
#include <Logger.h>
#include "KinesisVideoProducer.h"
#include <vector>
#include <stdlib.h>
#include <mutex>
#include <IotCertCredentialProvider.h>

(...)
(...)

// configure rtspsrc
    g_object_set(G_OBJECT (source),
                 "location", data->rtsp_url.c_str(),
                 "short-header", true, // Necessary for target camera
         "protocols", GST_RTSP_LOWER_TRANS_UDP, 
                 NULL);

However I still got the same error.

I'm aware that I won't be able to see the stream on AWS Management Console, as it's not yet supported, however, there is no stream being sent whatsoever.

So, my questions are: 1) Is it possible to send the H265 Stream to KVS using this producer SDK? 2) Can it be done using the sample multistream app or the sample app? 2.1) If so, what do I have to do to make it work? 2.2) If it's not possible, how can it be done?

Below are the DEBUG logs from both tries using the sample app:

Console Log - H265


[INFO ] [28-04-2020 22:44:21:603.871 GMT] Using region: us-west-2
[INFO ] [28-04-2020 22:44:21:604.146 GMT] Using aws credentials for Kinesis Video Streams
[INFO ] [28-04-2020 22:44:21:604.224 GMT] No session token was detected.
[INFO ] [28-04-2020 22:44:21:615.704 GMT] createKinesisVideoClient(): Creating Kinesis Video Client
[INFO ] [28-04-2020 22:44:21:615.995 GMT] heapInitialize(): Initializing native heap with limit size 134217728, spill ratio 0% and flags 0x00000001
[INFO ] [28-04-2020 22:44:21:616.069 GMT] heapInitialize(): Creating AIV heap.
[INFO ] [28-04-2020 22:44:21:616.255 GMT] heapInitialize(): Heap is initialized OK
[DEBUG] [28-04-2020 22:44:21:616.416 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[DEBUG] [28-04-2020 22:44:21:616.515 GMT] getSecurityTokenHandler invoked
[DEBUG] [28-04-2020 22:44:21:616.740 GMT] Refreshing credentials. Force refreshing: 0 Now time is: 1588113861616598212 Expiration: 0
[INFO ] [28-04-2020 22:44:21:616.850 GMT] New credentials expiration is 1588117461
[DEBUG] [28-04-2020 22:44:21:616.969 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000010
[INFO ] [28-04-2020 22:44:21:617.051 GMT] createDeviceResultEvent(): Create device result event.
[DEBUG] [28-04-2020 22:44:21:617.143 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [28-04-2020 22:44:21:617.218 GMT] clientReadyHandler invoked
[DEBUG] [28-04-2020 22:44:21:617.300 GMT] Client is ready
[INFO ] [28-04-2020 22:44:21:617.468 GMT] Creating Kinesis Video Stream xxxxxxxxxx-stream
[INFO ] [28-04-2020 22:44:21:617.559 GMT] createKinesisVideoStream(): Creating Kinesis Video Stream.
[DEBUG] [28-04-2020 22:44:21:617.639 GMT] logStreamInfo(): Kinesis Video Stream Info
[DEBUG] [28-04-2020 22:44:21:617.698 GMT] logStreamInfo():  Stream name: xxxxxxxxxx-stream 
[DEBUG] [28-04-2020 22:44:21:617.756 GMT] logStreamInfo():  Streaming type: STREAMING_TYPE_REALTIME 
[DEBUG] [28-04-2020 22:44:21:617.814 GMT] logStreamInfo():  Content type: video/h264 
[DEBUG] [28-04-2020 22:44:21:617.874 GMT] logStreamInfo():  Max latency (100ns): 600000000
[DEBUG] [28-04-2020 22:44:21:617.932 GMT] logStreamInfo():  Fragment duration (100ns): 20000000
[DEBUG] [28-04-2020 22:44:21:617.990 GMT] logStreamInfo():  Key frame fragmentation: Yes
[DEBUG] [28-04-2020 22:44:21:618.045 GMT] logStreamInfo():  Use frame timecode: Yes
[DEBUG] [28-04-2020 22:44:21:618.101 GMT] logStreamInfo():  Absolute frame timecode: Yes
[DEBUG] [28-04-2020 22:44:21:618.159 GMT] logStreamInfo():  Nal adaptation flags: 0
[DEBUG] [28-04-2020 22:44:21:618.215 GMT] logStreamInfo():  Average bandwith (bps): 4194304
[DEBUG] [28-04-2020 22:44:21:618.272 GMT] logStreamInfo():  Framerate: 25
[DEBUG] [28-04-2020 22:44:21:618.327 GMT] logStreamInfo():  Buffer duration (100ns): 1200000000
[DEBUG] [28-04-2020 22:44:21:618.421 GMT] logStreamInfo():  Replay duration (100ns): 400000000
[DEBUG] [28-04-2020 22:44:21:618.571 GMT] logStreamInfo():  Connection Staleness duration (100ns): 600000000
[DEBUG] [28-04-2020 22:44:21:618.715 GMT] logStreamInfo():  Store Pressure Policy: 0
[DEBUG] [28-04-2020 22:44:21:618.859 GMT] logStreamInfo():  View Overflow Policy: 0
[DEBUG] [28-04-2020 22:44:21:619.008 GMT] logStreamInfo():  Segment UUID: NULL
[DEBUG] [28-04-2020 22:44:21:619.150 GMT] logStreamInfo():  Frame ordering mode: 0
[DEBUG] [28-04-2020 22:44:21:619.291 GMT] logStreamInfo(): Track list
[DEBUG] [28-04-2020 22:44:21:619.389 GMT] logStreamInfo():  Track id: 1
[DEBUG] [28-04-2020 22:44:21:619.528 GMT] logStreamInfo():  Track name: kinesis_video
[DEBUG] [28-04-2020 22:44:21:619.627 GMT] logStreamInfo():  Codec id: V_MPEG4/ISO/AVC
[DEBUG] [28-04-2020 22:44:21:619.687 GMT] logStreamInfo():  Track type: TRACK_INFO_TYPE_VIDEO
[DEBUG] [28-04-2020 22:44:21:619.744 GMT] logStreamInfo():  Track cpd: NULL
[DEBUG] [28-04-2020 22:44:21:620.148 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[INFO ] [28-04-2020 22:44:23:630.397 GMT] writeHeaderCallback(): RequestId: 394407a2-3aa9-4dd7-a0e6-ba5aab18fefb
[DEBUG] [28-04-2020 22:44:23:630.749 GMT] describeStreamCurlHandler(): DescribeStream API response: {"StreamInfo":{"CreationTime":1.586210606267E9,"DataRetentionInHours":1,"DeviceName":"Kinesis_Video_Device","KmsKeyId":"arn:aws:kms:us-west-2:xxxxxxxx:alias/aws/kinesisvideo","MediaType":"video/h264","Status":"ACTIVE","StreamARN":"arn:aws:kinesisvideo:us-west-2:xxxxxxxx:stream/xxxxxxxxxx-stream/1586210606267","StreamName":"xxxxxxxxxx-stream","Version":"a5TPP3tumlG7Lwer37IW"}}
[INFO ] [28-04-2020 22:44:23:632.015 GMT] describeStreamResultEvent(): Describe stream result event.
[WARN ] [28-04-2020 22:44:23:632.153 GMT] describeStreamResult(): Retention period returned from the DescribeStream call doesn't match the one specified in the StreamInfo
[DEBUG] [28-04-2020 22:44:23:632.242 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000020
[INFO ] [28-04-2020 22:44:25:647.928 GMT] writeHeaderCallback(): RequestId: 081d71f7-23a4-411a-b11a-4e230b8fbb59
[DEBUG] [28-04-2020 22:44:25:648.231 GMT] getStreamingEndpointCurlHandler(): GetStreamingEndpoint API response: {"DataEndpoint":"https://s-xxxxxxxxx.kinesisvideo.us-west-2.amazonaws.com"}
[INFO ] [28-04-2020 22:44:25:649.321 GMT] getStreamingEndpointResultEvent(): Get streaming endpoint result event.
[DEBUG] [28-04-2020 22:44:25:649.483 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000020, Next state: 0x0000000000000010
[DEBUG] [28-04-2020 22:44:25:649.572 GMT] getStreamingTokenHandler invoked
[DEBUG] [28-04-2020 22:44:25:649.698 GMT] Refreshing credentials. Force refreshing: 1 Now time is: 1588113865649645991 Expiration: 1588117461
[INFO ] [28-04-2020 22:44:25:649.777 GMT] New credentials expiration is 1588117465
[INFO ] [28-04-2020 22:44:25:649.887 GMT] getStreamingTokenResultEvent(): Get streaming token result event.
[DEBUG] [28-04-2020 22:44:25:649.984 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [28-04-2020 22:44:25:650.068 GMT] streamReadyHandler invoked
[DEBUG] [28-04-2020 22:44:25:650.308 GMT] Stream is ready
[INFO ] [28-04-2020 22:44:25:755.804 GMT] Streaming from rtsp source
New pad found: recv_rtp_src_0_172791707_96
[INFO ] [28-04-2020 22:44:26:025.701 GMT] Pad link failed
Error received from element udpsrc1: Internal data stream error.
Debugging information: gstbasesrc.c(3055): gst_base_src_loop (): /GstPipeline:rtsp-kinesis-pipeline/GstRTSPSrc:source/GstUDPSrc:udpsrc1:
streaming stopped, reason not-linked (-1)
[INFO ] [28-04-2020 22:44:26:031.893 GMT] stopKinesisVideoStreamSync(): Synchronously stopping Kinesis Video Stream 0000000000d5c738.
[DEBUG] [28-04-2020 22:44:26:032.057 GMT] streamClosedHandler invoked for upload handle: 18446744073709551615
[INFO ] [28-04-2020 22:44:26:032.138 GMT] Freeing Kinesis Video Stream xxxxxxxxxx-stream
[INFO ] [28-04-2020 22:44:26:032.197 GMT] freeKinesisVideoStream(): Freeing Kinesis Video stream.
[DEBUG] [28-04-2020 22:44:26:032.249 GMT] curlApiCallbacksShutdownActiveRequests(): pActiveRequests hashtable is empty
[INFO ] [28-04-2020 22:44:26:432.625 GMT] Freeing Kinesis Video Stream xxxxxxxxxx-stream
[INFO ] [28-04-2020 22:44:26:432.715 GMT] freeKinesisVideoClient(): Freeing Kinesis Video Client
[DEBUG] [28-04-2020 22:44:26:432.767 GMT] curlApiCallbacksShutdownActiveRequests(): pActiveRequests hashtable is empty
[DEBUG] [28-04-2020 22:44:26:835.010 GMT] freeKinesisVideoClientInternal(): Total allocated memory 0
[WARN ] [28-04-2020 22:44:26:835.264 GMT] curlApiCallbacksShutdown(): curlApiCallbacksShutdown called when already in progress of shutting down

Console Log - H264

[INFO ] [28-04-2020 23:11:01:472.491 GMT] Using region: us-west-2
[INFO ] [28-04-2020 23:11:01:472.667 GMT] Using aws credentials for Kinesis Video Streams
[INFO ] [28-04-2020 23:11:01:472.744 GMT] No session token was detected.
[INFO ] [28-04-2020 23:11:01:484.130 GMT] createKinesisVideoClient(): Creating Kinesis Video Client
[INFO ] [28-04-2020 23:11:01:484.412 GMT] heapInitialize(): Initializing native heap with limit size 134217728, spill ratio 0% and flags 0x00000001
[INFO ] [28-04-2020 23:11:01:484.485 GMT] heapInitialize(): Creating AIV heap.
[INFO ] [28-04-2020 23:11:01:484.658 GMT] heapInitialize(): Heap is initialized OK
[DEBUG] [28-04-2020 23:11:01:484.816 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[DEBUG] [28-04-2020 23:11:01:484.915 GMT] getSecurityTokenHandler invoked
[DEBUG] [28-04-2020 23:11:01:485.148 GMT] Refreshing credentials. Force refreshing: 0 Now time is: 1588115461485000520 Expiration: 0
[INFO ] [28-04-2020 23:11:01:485.258 GMT] New credentials expiration is 1588119061
[DEBUG] [28-04-2020 23:11:01:485.385 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000010
[INFO ] [28-04-2020 23:11:01:485.467 GMT] createDeviceResultEvent(): Create device result event.
[DEBUG] [28-04-2020 23:11:01:485.559 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [28-04-2020 23:11:01:485.633 GMT] clientReadyHandler invoked
[DEBUG] [28-04-2020 23:11:01:485.720 GMT] Client is ready
[INFO ] [28-04-2020 23:11:01:485.892 GMT] Creating Kinesis Video Stream xxxxxxx-stream
[INFO ] [28-04-2020 23:11:01:485.981 GMT] createKinesisVideoStream(): Creating Kinesis Video Stream.
[DEBUG] [28-04-2020 23:11:01:486.061 GMT] logStreamInfo(): Kinesis Video Stream Info
[DEBUG] [28-04-2020 23:11:01:486.105 GMT] logStreamInfo():  Stream name: xxxxxxx-stream 
[DEBUG] [28-04-2020 23:11:01:486.134 GMT] logStreamInfo():  Streaming type: STREAMING_TYPE_REALTIME 
[DEBUG] [28-04-2020 23:11:01:486.164 GMT] logStreamInfo():  Content type: video/h264 
[DEBUG] [28-04-2020 23:11:01:486.195 GMT] logStreamInfo():  Max latency (100ns): 600000000
[DEBUG] [28-04-2020 23:11:01:486.224 GMT] logStreamInfo():  Fragment duration (100ns): 20000000
[DEBUG] [28-04-2020 23:11:01:486.252 GMT] logStreamInfo():  Key frame fragmentation: Yes
[DEBUG] [28-04-2020 23:11:01:486.281 GMT] logStreamInfo():  Use frame timecode: Yes
[DEBUG] [28-04-2020 23:11:01:486.310 GMT] logStreamInfo():  Absolute frame timecode: Yes
[DEBUG] [28-04-2020 23:11:01:486.340 GMT] logStreamInfo():  Nal adaptation flags: 0
[DEBUG] [28-04-2020 23:11:01:486.368 GMT] logStreamInfo():  Average bandwith (bps): 4194304
[DEBUG] [28-04-2020 23:11:01:486.408 GMT] logStreamInfo():  Framerate: 25
[DEBUG] [28-04-2020 23:11:01:486.436 GMT] logStreamInfo():  Buffer duration (100ns): 1200000000
[DEBUG] [28-04-2020 23:11:01:486.465 GMT] logStreamInfo():  Replay duration (100ns): 400000000
[DEBUG] [28-04-2020 23:11:01:486.494 GMT] logStreamInfo():  Connection Staleness duration (100ns): 600000000
[DEBUG] [28-04-2020 23:11:01:486.524 GMT] logStreamInfo():  Store Pressure Policy: 0
[DEBUG] [28-04-2020 23:11:01:486.552 GMT] logStreamInfo():  View Overflow Policy: 0
[DEBUG] [28-04-2020 23:11:01:486.580 GMT] logStreamInfo():  Segment UUID: NULL
[DEBUG] [28-04-2020 23:11:01:486.608 GMT] logStreamInfo():  Frame ordering mode: 0
[DEBUG] [28-04-2020 23:11:01:486.635 GMT] logStreamInfo(): Track list
[DEBUG] [28-04-2020 23:11:01:486.662 GMT] logStreamInfo():  Track id: 1
[DEBUG] [28-04-2020 23:11:01:486.690 GMT] logStreamInfo():  Track name: kinesis_video
[DEBUG] [28-04-2020 23:11:01:486.718 GMT] logStreamInfo():  Codec id: V_MPEG4/ISO/AVC
[DEBUG] [28-04-2020 23:11:01:486.746 GMT] logStreamInfo():  Track type: TRACK_INFO_TYPE_VIDEO
[DEBUG] [28-04-2020 23:11:01:486.774 GMT] logStreamInfo():  Track cpd: NULL
[DEBUG] [28-04-2020 23:11:01:487.001 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[INFO ] [28-04-2020 23:11:02:473.495 GMT] writeHeaderCallback(): RequestId: ecbacf9f-e26c-4d6e-a871-9b00c01e1a89
[DEBUG] [28-04-2020 23:11:02:473.848 GMT] describeStreamCurlHandler(): DescribeStream API response: {"StreamInfo":{"CreationTime":1.586210606267E9,"DataRetentionInHours":1,"DeviceName":"Kinesis_Video_Device","KmsKeyId":"arn:aws:kms:us-west-2:xxxxxxxxxxxx:alias/aws/kinesisvideo","MediaType":"video/h264","Status":"ACTIVE","StreamARN":"arn:aws:kinesisvideo:us-west-2:xxxxxxxxxxxx:stream/xxxxxxx-stream/yyyyyyyyy","StreamName":"xxxxxxx-stream","Version":"a5TPP3tumlG7Lwer37IW"}}
[INFO ] [28-04-2020 23:11:02:475.283 GMT] describeStreamResultEvent(): Describe stream result event.
[WARN ] [28-04-2020 23:11:02:475.433 GMT] describeStreamResult(): Retention period returned from the DescribeStream call doesn't match the one specified in the StreamInfo
[DEBUG] [28-04-2020 23:11:02:475.521 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000020
[INFO ] [28-04-2020 23:11:03:467.787 GMT] writeHeaderCallback(): RequestId: a32d2cdd-b203-4429-bbab-e51d4b57f27f
[DEBUG] [28-04-2020 23:11:03:468.037 GMT] getStreamingEndpointCurlHandler(): GetStreamingEndpoint API response: {"DataEndpoint":"https://s-xxxxxxx.kinesisvideo.us-west-2.amazonaws.com"}
[INFO ] [28-04-2020 23:11:03:469.114 GMT] getStreamingEndpointResultEvent(): Get streaming endpoint result event.
[DEBUG] [28-04-2020 23:11:03:469.281 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000020, Next state: 0x0000000000000010
[DEBUG] [28-04-2020 23:11:03:469.370 GMT] getStreamingTokenHandler invoked
[DEBUG] [28-04-2020 23:11:03:469.494 GMT] Refreshing credentials. Force refreshing: 1 Now time is: 1588115463469444542 Expiration: 1588119061
[INFO ] [28-04-2020 23:11:03:469.571 GMT] New credentials expiration is 1588119063
[INFO ] [28-04-2020 23:11:03:469.678 GMT] getStreamingTokenResultEvent(): Get streaming token result event.
[DEBUG] [28-04-2020 23:11:03:469.773 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [28-04-2020 23:11:03:469.904 GMT] streamReadyHandler invoked
[DEBUG] [28-04-2020 23:11:03:470.117 GMT] Stream is ready
[INFO ] [28-04-2020 23:11:03:577.142 GMT] Streaming from rtsp source
New pad found: recv_rtp_src_0_970388452_96
[INFO ] [28-04-2020 23:11:03:867.513 GMT] Pad link successful
[INFO ] [28-04-2020 23:11:03:874.005 GMT] kinesisVideoStreamFormatChanged(): Stream format changed.
[WARN ] [28-04-2020 23:11:03:874.341 GMT] mkvgenAdaptCodecPrivateData(): Failed extracting video configuration from SPS with 41000001.
[DEBUG] [28-04-2020 23:11:03:874.520 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000040, Next state: 0x0000000000000080
[INFO ] [28-04-2020 23:11:03:875.019 GMT] putStreamResultEvent(): Put stream result event. New upload handle 0
[DEBUG] [28-04-2020 23:11:03:885.322 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000080, Next state: 0x0000000000000100
[DEBUG] [28-04-2020 23:11:03:886.089 GMT] Kinesis Video client and stream metrics
    >> Overall storage byte size: 134217728
    >> Available storage byte size: 134200609
    >> Allocated storage byte size: 17119
    >> Total view allocation byte size: 144080
    >> Total streams frame rate (fps): 25
    >> Total streams transfer rate (bps): 33554432 (32768 Kbps)
    >> Current view duration (ms): 0
    >> Overall view duration (ms): 0
    >> Current view byte size: 17079
    >> Overall view byte size: 17079
    >> Current frame rate (fps): 25
    >> Current transfer rate (bps): 33554432 (32768 Kbps)
[INFO ] [28-04-2020 23:11:05:086.625 GMT] writeHeaderCallback(): RequestId: db6eb15a-6551-7d69-8c4c-0b120d7b32e1
[DEBUG] [28-04-2020 23:11:05:087.504 GMT] postReadCallback(): Wrote 44179 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:05:319.685 GMT] postReadCallback(): Wrote 3530 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:05:320.519 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:05:554.327 GMT] postWriteCallback(): Curl post body write function for stream with handle: xxxxxxx-stream and upload handle: 0 returned: {"EventType":"BUFFERING","FragmentTimecode":aaaaaaaaaa,"FragmentNumber":"bbbbbbbbbb"}

[DEBUG] [28-04-2020 23:11:05:555.076 GMT] fragmentAckReceivedHandler invoked
[DEBUG] [28-04-2020 23:11:05:555.735 GMT] Reporting fragment ack received. Ack timecode aaaaaaaaaa
[DEBUG] [28-04-2020 23:11:05:556.407 GMT] postReadCallback(): Wrote 3956 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:05:557.545 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:06:559.275 GMT] postReadCallback(): Wrote 16042 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:06:560.626 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:07:561.935 GMT] postReadCallback(): Wrote 21177 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:07:563.980 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:07:743.870 GMT] Kinesis Video client and stream metrics
    >> Overall storage byte size: 134217728
    >> Available storage byte size: 134106542
    >> Allocated storage byte size: 111186
    >> Total view allocation byte size: 144080
    >> Total streams frame rate (fps): 18
    >> Total streams transfer rate (bps): 25989528 (25380 Kbps)
    >> Current view duration (ms): 120
    >> Overall view duration (ms): 3867
    >> Current view byte size: 20178
    >> Overall view byte size: 108784
    >> Current frame rate (fps): 18.2941
    >> Current transfer rate (bps): 25989528 (25380 Kbps)
[DEBUG] [28-04-2020 23:11:08:565.470 GMT] postReadCallback(): Wrote 41295 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:08:568.777 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:08:886.796 GMT] postReadCallback(): Wrote 5891 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:08:888.033 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:09:246.301 GMT] postWriteCallback(): Curl post body write function for stream with handle: xxxxxxx-stream and upload handle: 0 returned: {"EventType":"RECEIVED","FragmentTimecode":aaaaaaaaaa,"FragmentNumber":"bbbbbbbbbb"}

[DEBUG] [28-04-2020 23:11:09:247.030 GMT] fragmentAckReceivedHandler invoked
[DEBUG] [28-04-2020 23:11:09:247.679 GMT] Reporting fragment ack received. Ack timecode aaaaaaaaaa
[DEBUG] [28-04-2020 23:11:09:248.309 GMT] postReadCallback(): Wrote 7087 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:09:249.254 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:09:253.636 GMT] postWriteCallback(): Curl post body write function for stream with handle: xxxxxxx-stream and upload handle: 0 returned: {"EventType":"BUFFERING","FragmentTimecode":cccccccccc,"FragmentNumber":"ddddddddddd"}

[DEBUG] [28-04-2020 23:11:09:254.939 GMT] fragmentAckReceivedHandler invoked
[DEBUG] [28-04-2020 23:11:09:256.339 GMT] Reporting fragment ack received. Ack timecode cccccccccc
[DEBUG] [28-04-2020 23:11:09:358.558 GMT] postWriteCallback(): Curl post body write function for stream with handle: xxxxxxx-stream and upload handle: 0 returned: {"EventType":"PERSISTED","FragmentTimecode":aaaaaaaaaa,"FragmentNumber":"bbbbbbbbbb"}

[DEBUG] [28-04-2020 23:11:09:360.134 GMT] fragmentAckReceivedHandler invoked
[DEBUG] [28-04-2020 23:11:09:360.447 GMT] Reporting fragment ack received. Ack timecode aaaaaaaaaa
[DEBUG] [28-04-2020 23:11:09:360.790 GMT] postReadCallback(): Wrote 2899 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:09:361.472 GMT] postReadCallback(): Pausing CURL read for upload handle: 0
[DEBUG] [28-04-2020 23:11:10:363.216 GMT] postReadCallback(): Wrote 16486 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [28-04-2020 23:11:10:365.202 GMT] postReadCallback(): Pausing CURL read for upload handle: 0

(...)
MushMal commented 4 years ago

@dvsantana the issue really is about how to configure the RTSP plugin rather the KVS itself. The KVS does support H265 ingestion and playback in the console (as long as your browser supports the MSE with H265).

Could you please enable GStreamer debug logs to understand why the Pads are not being negotiated?

Set GST_DEBUG=4 env var like so

export GST_DEBUG=4

dvsantana commented 4 years ago

@MushMal, thanks for the quick reply! The log was very long this time:

[INFO ] [29-04-2020 12:53:28:849.811 GMT] Using region: us-west-2
[INFO ] [29-04-2020 12:53:28:850.179 GMT] Using aws credentials for Kinesis Video Streams
[INFO ] [29-04-2020 12:53:28:850.255 GMT] No session token was detected.
[INFO ] [29-04-2020 12:53:28:862.214 GMT] createKinesisVideoClient(): Creating Kinesis Video Client
[INFO ] [29-04-2020 12:53:28:862.558 GMT] heapInitialize(): Initializing native heap with limit size 134217728, spill ratio 0% and flags 0x00000001
[INFO ] [29-04-2020 12:53:28:862.634 GMT] heapInitialize(): Creating AIV heap.
[INFO ] [29-04-2020 12:53:28:862.795 GMT] heapInitialize(): Heap is initialized OK
[DEBUG] [29-04-2020 12:53:28:862.965 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[DEBUG] [29-04-2020 12:53:28:863.090 GMT] getSecurityTokenHandler invoked
[DEBUG] [29-04-2020 12:53:28:863.363 GMT] Refreshing credentials. Force refreshing: 0 Now time is: 1588164808863194936 Expiration: 0
[INFO ] [29-04-2020 12:53:28:863.487 GMT] New credentials expiration is 1588168408
[DEBUG] [29-04-2020 12:53:28:863.642 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000010
[INFO ] [29-04-2020 12:53:28:863.730 GMT] createDeviceResultEvent(): Create device result event.
[DEBUG] [29-04-2020 12:53:28:863.842 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [29-04-2020 12:53:28:863.922 GMT] clientReadyHandler invoked
[DEBUG] [29-04-2020 12:53:28:864.124 GMT] Client is ready
[INFO ] [29-04-2020 12:53:28:864.656 GMT] Creating Kinesis Video Stream xxxxx-stream
[INFO ] [29-04-2020 12:53:28:864.883 GMT] createKinesisVideoStream(): Creating Kinesis Video Stream.
[DEBUG] [29-04-2020 12:53:28:864.970 GMT] logStreamInfo(): Kinesis Video Stream Info
[DEBUG] [29-04-2020 12:53:28:865.038 GMT] logStreamInfo():  Stream name: xxxxx-stream 
[DEBUG] [29-04-2020 12:53:28:865.105 GMT] logStreamInfo():  Streaming type: STREAMING_TYPE_REALTIME 
[DEBUG] [29-04-2020 12:53:28:865.169 GMT] logStreamInfo():  Content type: video/h264 
[DEBUG] [29-04-2020 12:53:28:865.236 GMT] logStreamInfo():  Max latency (100ns): 600000000
[DEBUG] [29-04-2020 12:53:28:865.301 GMT] logStreamInfo():  Fragment duration (100ns): 20000000
[DEBUG] [29-04-2020 12:53:28:865.366 GMT] logStreamInfo():  Key frame fragmentation: Yes
[DEBUG] [29-04-2020 12:53:28:865.430 GMT] logStreamInfo():  Use frame timecode: Yes
[DEBUG] [29-04-2020 12:53:28:865.493 GMT] logStreamInfo():  Absolute frame timecode: Yes
[DEBUG] [29-04-2020 12:53:28:865.558 GMT] logStreamInfo():  Nal adaptation flags: 0
[DEBUG] [29-04-2020 12:53:28:865.623 GMT] logStreamInfo():  Average bandwith (bps): 4194304
[DEBUG] [29-04-2020 12:53:28:865.688 GMT] logStreamInfo():  Framerate: 25
[DEBUG] [29-04-2020 12:53:28:865.752 GMT] logStreamInfo():  Buffer duration (100ns): 1200000000
[DEBUG] [29-04-2020 12:53:28:865.817 GMT] logStreamInfo():  Replay duration (100ns): 400000000
[DEBUG] [29-04-2020 12:53:28:865.883 GMT] logStreamInfo():  Connection Staleness duration (100ns): 600000000
[DEBUG] [29-04-2020 12:53:28:865.949 GMT] logStreamInfo():  Store Pressure Policy: 1
[DEBUG] [29-04-2020 12:53:28:866.015 GMT] logStreamInfo():  View Overflow Policy: 1
[DEBUG] [29-04-2020 12:53:28:866.080 GMT] logStreamInfo():  Segment UUID: NULL
[DEBUG] [29-04-2020 12:53:28:866.144 GMT] logStreamInfo():  Frame ordering mode: 0
[DEBUG] [29-04-2020 12:53:28:866.207 GMT] logStreamInfo(): Track list
[DEBUG] [29-04-2020 12:53:28:866.271 GMT] logStreamInfo():  Track id: 1
[DEBUG] [29-04-2020 12:53:28:866.333 GMT] logStreamInfo():  Track name: kinesis_video
[DEBUG] [29-04-2020 12:53:28:866.397 GMT] logStreamInfo():  Codec id: V_MPEG4/ISO/AVC
[DEBUG] [29-04-2020 12:53:28:866.461 GMT] logStreamInfo():  Track type: TRACK_INFO_TYPE_VIDEO
[DEBUG] [29-04-2020 12:53:28:866.524 GMT] logStreamInfo():  Track cpd: NULL
[DEBUG] [29-04-2020 12:53:28:866.876 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[INFO ] [29-040:00:00.000547187  1051  0x1e89e00 INFO                GST_INIT gst.c:586:init_pre: Initializing GStreamer Core Library version 1.14.4
0:00:00.000822760  1051  0x1e89e00 INFO                GST_INIT gst.c:587:init_pre: Using library installed in /usr/lib/arm-linux-gnueabihf
0:00:00.000924427  1051  0x1e89e00 INFO                GST_INIT gst.c:607:init_pre: Linux raspberrypi 4.19.97-v7+ #1294 SMP Thu Jan 30 13:15:58 GMT 2020 armv7l
0:00:00.002469843  1051  0x1e89e00 INFO                GST_INIT gstmessage.c:127:_priv_gst_message_initialize: init messages
0:00:00.005786925  1051  0x1e89e00 INFO                GST_INIT gstcontext.c:84:_priv_gst_context_initialize: init contexts
0:00:00.007263747  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:317:_priv_gst_plugin_initialize: registering 0 static plugins
0:00:00.007927809  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:225:gst_plugin_register_static: registered static plugin "staticelements"
0:00:00.008013903  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:227:gst_plugin_register_static: added static plugin "staticelements", result: 1
0:00:00.008152393  1051  0x1e89e00 INFO            GST_REGISTRY gstregistry.c:1727:ensure_current_registry: reading registry cache: /home/pi/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.095871527  1051  0x1e89e00 INFO            GST_REGISTRY gstregistrybinary.c:621:priv_gst_registry_binary_read_cache: loaded /home/pi/.cache/gstreamer-1.0/registry.arm.bin in 0.087550 seconds
0:00:00.096234339  1051  0x1e89e00 INFO            GST_REGISTRY gstregistry.c:1583:scan_and_update_registry: Validating plugins from registry cache: /home/pi/.cache/gstreamer-1.0/registry.arm.bin
0:00:00.105237877  1051  0x1e89e00 INFO            GST_REGISTRY gstregistry.c:1685:scan_and_update_registry: Registry cache has not changed
0:00:00.105377669  1051  0x1e89e00 INFO            GST_REGISTRY gstregistry.c:1762:ensure_current_registry: registry reading and updating done, result = 1
0:00:00.105444909  1051  0x1e89e00 INFO                GST_INIT gst.c:807:init_post: GLib runtime version: 2.58.3
0:00:00.105513971  1051  0x1e89e00 INFO                GST_INIT gst.c:809:init_post: GLib headers version: 2.58.1
0:00:00.105566523  1051  0x1e89e00 INFO                GST_INIT gst.c:810:init_post: initialized GStreamer successfully
0:00:00.105938294  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "pipeline" named "rtsp-kinesis-pipeline"
0:00:00.110903448  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstcoreelements.so" loaded
0:00:00.111066104  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "capsfilter" named "filter"
0:00:00.111897458  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseTransform@0x1edc0a8> adding pad 'sink'
0:00:00.112048969  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseTransform@0x1edc0a8> adding pad 'src'
0:00:00.113454489  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstapp.so" loaded
0:00:00.113611624  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "appsink" named "appsink"
0:00:00.114482718  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSink@0x1edb8d0> adding pad 'sink'
0:00:00.129459014  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrtp.so" loaded
0:00:00.129631618  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "rtph264depay" named "depay"
0:00:00.130229379  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRTPBaseDepayload@0x1fa0070> adding pad 'sink'
0:00:00.130365681  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRTPBaseDepayload@0x1fa0070> adding pad 'src'
0:00:00.148873538  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrtsp.so" loaded
0:00:00.149038486  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "rtspsrc" named "source"
0:00:00.155438380  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstasf.so" loaded
0:00:00.155581192  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "rtspwms"
0:00:00.158802441  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrealmedia.so" loaded
0:00:00.158936347  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "rtspreal"
0:00:00.162524887  1051  0x1e89e00 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstvideoparsersbad.so" loaded
0:00:00.162657387  1051  0x1e89e00 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "h264parse" named "h264parse"
0:00:00.163244523  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseParse@0x1fb0208> adding pad 'sink'
0:00:00.163392647  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseParse@0x1fb0208> adding pad 'src'
0:00:00.163585720  1051  0x1e89e00 INFO               baseparse gstbaseparse.c:3961:gst_base_parse_set_pts_interpolation:<GstH264Parse@0x1fb0208> PTS interpolation: no
0:00:00.163757127  1051  0x1e89e00 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.164318845  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element depay:(any) to element filter:(any)
0:00:00.164413637  1051  0x1e89e00 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link depay:src and filter:sink
0:00:00.164634001  1051  0x1e89e00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<filter:src> pad has no peer
0:00:00.164763064  1051  0x1e89e00 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: depay and filter in same bin, no need for ghost pads
0:00:00.164878637  1051  0x1e89e00 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link depay:src and filter:sink
0:00:00.164977699  1051  0x1e89e00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<filter:src> pad has no peer
0:00:00.165084157  1051  0x1e89e00 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked depay:src and filter:sink, successful
0:00:00.165143011  1051  0x1e89e00 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.165204730  1051  0x1e89e00 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<depay:src> Received event on flushing pad. Discarding
0:00:00.165323063  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element filter:(any) to element h264parse:(any)
0:00:00.165409990  1051  0x1e89e00 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link filter:src and h264parse:sink
0:00:00.165559990  1051  0x1e89e00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<h264parse:src> pad has no peer
0:00:00.165683949  1051  0x1e89e00 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: filter and h264parse in same bin, no need for ghost pads
0:00:00.165792022  1051  0x1e89e00 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link filter:src and h264parse:sink
0:00:00.165927282  1051  0x1e89e00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<h264parse:src> pad has no peer
0:00:00.166047699  1051  0x1e89e00 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked filter:src and h264parse:sink, successful
0:00:00.166106344  1051  0x1e89e00 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.166167438  1051  0x1e89e00 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<filter:src> Received event on flushing pad. Discarding
0:00:00.166274001  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element h264parse:(any) to element appsink:(any)
0:00:00.166361396  1051  0x1e89e00 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link h264parse:src and appsink:sink
0:00:00.166487073  1051  0x1e89e00 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: h264parse and appsink in same bin, no need for ghost pads
0:00:00.166692282  1051  0x1e89e00 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link h264parse:src and appsink:sink
0:00:00.166812177  1051  0x1e89e00 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked h264parse:src and appsink:sink, successful
0:00:00.166870615  1051  0x1e89e00 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.166969417  1051  0x1e89e00 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<h264parse:src> Received event on flushing pad. Discarding
0:00:00.167303584  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<appsink> current NULL pending VOID_PENDING, desired next READY
0:00:00.167392802  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<appsink> completed state change to READY
0:00:00.167470094  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<appsink> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.167622750  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'appsink' changed state to 2(READY) successfully
0:00:00.167718479  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h264parse> current NULL pending VOID_PENDING, desired next READY
0:00:00.167791292  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h264parse> completed state change to READY
0:00:00.167867542  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h264parse> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.167966917  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'h264parse' changed state to 2(READY) successfully
0:00:00.168057542  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filter> current NULL pending VOID_PENDING, desired next READY
0:00:00.168128375  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<filter> completed state change to READY
0:00:00.168202750  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filter> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.168299625  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'filter' changed state to 2(READY) successfully
0:00:00.168384885  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<depay> current NULL pending VOID_PENDING, desired next READY
0:00:00.168456552  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<depay> completed state change to READY
0:00:00.168530510  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<depay> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.168627229  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'depay' changed state to 2(READY) successfully
0:00:00.168713583  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<source> current NULL pending VOID_PENDING, desired next READY
0:00:00.168865875  1051  0x1e89e00 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x1faa280 on task 0x1fb4828
0:00:00.168962281  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<source> completed state change to READY
0:00:00.169078166  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<source> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.169178010  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'source' changed state to 2(READY) successfully
0:00:00.169272281  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtsp-kinesis-pipeline> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.169351395  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtsp-kinesis-pipeline> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.169443999  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtsp-kinesis-pipeline> continue state change READY to PAUSED, final PLAYING
0:00:00.169567593  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<appsink> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.169703531  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2960:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'appsink' is changing state asynchronously to PAUSED
0:00:00.169798010  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h264parse> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.170924363  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h264parse> completed state change to PAUSED
0:00:00.171051082  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h264parse> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.171167436  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'h264parse' changed state to 3(PAUSED) successfully
0:00:00.171271707  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filter> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.171394624  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<filter> completed state change to PAUSED
0:00:00.171472384  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filter> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.171575926  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'filter' changed state to 3(PAUSED) successfully
0:00:00.171662696  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<depay> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.171765040  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<depay> completed state change to PAUSED
0:00:00.171844155  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<depay> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.171944311  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'depay' changed state to 3(PAUSED) successfully
0:00:00.172099415  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<source> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.172432175  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<source> completed state change to PAUSED
0:00:00.172517384  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<source> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.172644571  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2997:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'source' changed state to 3(PAUSED) successfully without preroll
0:00:00.172758113  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtsp-kinesis-pipeline> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.172868842  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtsp-kinesis-pipeline> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.172988113  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtsp-kinesis-pipeline> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.173874675  1051  0x1e89e00 INFO               GST_EVENT gstevent.c:1388:gst_event_new_latency: creating latency event 0:00:00.000000000
0:00:00.174069414  1051  0x1e89e00 INFO                     bin gstbin.c:2783:gst_bin_do_latency_func:<rtsp-kinesis-pipeline> configured latency of 0:00:00.000000000
0:00:00.174228008  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<appsink> current READY pending PAUSED, desired next PLAYING
0:00:00.174328112  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2960:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'appsink' is changing state asynchronously to PLAYING
0:00:00.174495977  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h264parse> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.174575456  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h264parse> completed state change to PLAYING
0:00:00.174665925  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h264parse> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.174788945  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'h264parse' changed state to 4(PLAYING) successfully
0:00:00.174888841  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filter> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.174960872  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<filter> completed state change to PLAYING
0:00:00.175037695  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filter> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.175141758  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'filter' changed state to 4(PLAYING) successfully
0:00:00.175293528  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<depay> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.175366028  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<depay> completed state change to PLAYING
0:00:00.175442278  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<depay> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.175555664  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'depay' changed state to 4(PLAYING) successfully
0:00:00.175713632  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<source> completed state change to PLAYING
0:00:00.175807174  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<source> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.175918945  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'source' changed state to 4(PLAYING) successfully
0:00:00.245842721  1051  0x1fb31b0 INFO                 rtspsrc gstrtspsrc.c:7360:gst_rtspsrc_retrieve_sdp:<source> Now using version: 1.0
0:00:00.326832378  1051  0x1fb31b0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstudp.so" loaded
0:00:00.326992222  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "udpsrc"
0:00:00.327835347  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSrc@0x6cf1c0b0> adding pad 'src'
0:00:00.328344669  1051  0x1fb31b0 INFO                  udpsrc gstudpsrc.c:1408:gst_udpsrc_open:<udpsrc0> setting udp buffer of 524288 bytes
0:00:00.328421492  1051  0x1fb31b0 INFO                  udpsrc gstudpsrc.c:1428:gst_udpsrc_open:<udpsrc0> have udp buffer of 327680 bytes
0:00:00.328574721  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc0> completed state change to READY
0:00:00.328656701  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc0> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.328873003  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc0> completed state change to NULL
0:00:00.328953888  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.329043992  1051  0x1fb31b0 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<udpsrc0> 0x6cf1c0b0 dispose
0:00:00.329115346  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<udpsrc0> removing pad 'src'
0:00:00.329249305  1051  0x1fb31b0 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<udpsrc0> 0x6cf1c0b0 parent class dispose
0:00:00.329338107  1051  0x1fb31b0 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<udpsrc0> 0x6cf1c0b0 finalize
0:00:00.329473732  1051  0x1fb31b0 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<udpsrc0> 0x6cf1c0b0 finalize parent
0:00:00.330310815  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "udpsrc"
0:00:00.330470502  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSrc@0x6cf1c418> adding pad 'src'
0:00:00.330899148  1051  0x1fb31b0 INFO                  udpsrc gstudpsrc.c:1408:gst_udpsrc_open:<udpsrc1> setting udp buffer of 524288 bytes
0:00:00.330975658  1051  0x1fb31b0 INFO                  udpsrc gstudpsrc.c:1428:gst_udpsrc_open:<udpsrc1> have udp buffer of 327680 bytes
0:00:00.331119460  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc1> completed state change to READY
0:00:00.331199252  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.331897897  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "udpsrc"
0:00:00.332044824  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSrc@0x6cf1c780> adding pad 'src'
0:00:00.332431855  1051  0x1fb31b0 INFO                  udpsrc gstudpsrc.c:1428:gst_udpsrc_open:<udpsrc2> have udp buffer of 163840 bytes
0:00:00.332575657  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc2> completed state change to READY
0:00:00.332656439  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc2> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.343133726  1051  0x1fb31b0 INFO      GST_PLUGIN_LOADING gstplugin.c:901:_priv_gst_plugin_load_file_for_registry: plugin "/usr/lib/arm-linux-gnueabihf/gstreamer-1.0/libgstrtpmanager.so" loaded
0:00:00.343298258  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "rtpbin" named "manager"
0:00:00.345458621  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<manager> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.345555340  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<manager> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.345713882  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<manager> continue state change READY to PAUSED, final PAUSED
0:00:00.345839142  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<manager> completed state change to PAUSED
0:00:00.345920132  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<manager> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.346305965  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'recv_rtp_sink_0' in element "manager"
0:00:00.346407579  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "rtpsession"
0:00:00.348587006  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "rtpssrcdemux"
0:00:00.349162058  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRtpSsrcDemux@0x6cf32008> adding pad 'sink'
0:00:00.349297110  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRtpSsrcDemux@0x6cf32008> adding pad 'rtcp_sink'
0:00:00.349407162  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "rtpstorage"
0:00:00.349898516  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRtpStorage@0x6cf33000> adding pad 'src'
0:00:00.349982161  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRtpStorage@0x6cf33000> adding pad 'sink'
0:00:00.350161380  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "funnel"
0:00:00.350517995  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstFunnel@0x6cf330c8> adding pad 'src'
0:00:00.350622786  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "funnel"
0:00:00.350802265  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstFunnel@0x6cf33190> adding pad 'src'
0:00:00.351496640  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtpssrcdemux0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.351582473  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpssrcdemux0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.351728567  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtpssrcdemux0> continue state change READY to PAUSED, final PAUSED
0:00:00.351828411  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpssrcdemux0> completed state change to PAUSED
0:00:00.351906900  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpssrcdemux0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.352038931  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtpsession0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.352118411  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpsession0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.352232942  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtpsession0> continue state change READY to PAUSED, final PAUSED
0:00:00.352319088  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpsession0> completed state change to PAUSED
0:00:00.352396588  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpsession0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.352585963  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<funnel0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.352665129  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.352777525  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<funnel0> continue state change READY to PAUSED, final PAUSED
0:00:00.352863306  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel0> completed state change to PAUSED
0:00:00.352940181  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.353062056  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<funnel1> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.353141691  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel1> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.353253931  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<funnel1> continue state change READY to PAUSED, final PAUSED
0:00:00.353342577  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel1> completed state change to PAUSED
0:00:00.353420025  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.353542160  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtpstorage0> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.353620389  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpstorage0> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.353734035  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtpstorage0> continue state change READY to PAUSED, final PAUSED
0:00:00.353823931  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpstorage0> completed state change to PAUSED
0:00:00.353899712  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpstorage0> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.354018827  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'recv_rtp_sink' in element "rtpsession0"
0:00:00.354220493  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpsession0> adding pad 'recv_rtp_sink'
0:00:00.354421587  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpsession0> adding pad 'recv_rtp_src'
0:00:00.354679555  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<funnel0> adding pad 'funnelpad0'
0:00:00.354765285  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad funnel0:src
0:00:00.354916014  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link funnel0:src and rtpsession0:recv_rtp_sink
0:00:00.355048982  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked funnel0:src and rtpsession0:recv_rtp_sink, successful
0:00:00.355109868  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.355476482  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link recv_rtp_sink_0:proxypad0 and funnel0:funnelpad0
0:00:00.355568826  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked recv_rtp_sink_0:proxypad0 and funnel0:funnelpad0, successful
0:00:00.355630493  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.355739243  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<manager> adding pad 'recv_rtp_sink_0'
0:00:00.355852420  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpsession0:recv_rtp_src
0:00:00.355941222  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpstorage0:sink
0:00:00.356043253  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpsession0:recv_rtp_src and rtpstorage0:sink
0:00:00.356147628  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<rtpstorage0:src> pad has no peer
0:00:00.356258044  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpsession0:recv_rtp_src and rtpstorage0:sink, successful
0:00:00.356317315  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.356450701  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpstorage0:src
0:00:00.356597784  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpssrcdemux0:sink
0:00:00.356709398  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpstorage0:src and rtpssrcdemux0:sink
0:00:00.356794971  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpstorage0:src and rtpssrcdemux0:sink, successful
0:00:00.356852523  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.357039294  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'recv_rtcp_sink_0' in element "manager"
0:00:00.357138252  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'recv_rtcp_sink' in element "rtpsession0"
0:00:00.357329346  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpsession0> adding pad 'recv_rtcp_sink'
0:00:00.357513409  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpsession0> adding pad 'sync_src'
0:00:00.357745231  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<funnel1> adding pad 'funnelpad1'
0:00:00.357833044  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpsession0:sync_src
0:00:00.357908461  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpssrcdemux0:rtcp_sink
0:00:00.358011325  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpsession0:sync_src and rtpssrcdemux0:rtcp_sink
0:00:00.358099554  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpsession0:sync_src and rtpssrcdemux0:rtcp_sink, successful
0:00:00.358158044  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.358265856  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad funnel1:src
0:00:00.358367471  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link funnel1:src and rtpsession0:recv_rtcp_sink
0:00:00.358490335  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked funnel1:src and rtpsession0:recv_rtcp_sink, successful
0:00:00.358551325  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.358794033  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link recv_rtcp_sink_0:proxypad1 and funnel1:funnelpad1
0:00:00.358884294  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked recv_rtcp_sink_0:proxypad1 and funnel1:funnelpad1, successful
0:00:00.358943408  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.359041377  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<manager> adding pad 'recv_rtcp_sink_0'
0:00:00.359176012  1051  0x1fb31b0 INFO                 rtspsrc gstrtspsrc.c:3629:gst_rtspsrc_stream_configure_manager:<source> configure bandwidth in session 0x6cf2e198
0:00:00.359484866  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad udpsrc1:src
0:00:00.359636064  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link udpsrc1:src and manager:recv_rtp_sink_0
0:00:00.359723981  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked udpsrc1:src and manager:recv_rtp_sink_0, successful
0:00:00.359783668  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.359845439  1051  0x1fb31b0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<udpsrc1:src> Received event on flushing pad. Discarding
0:00:00.360041012  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad udpsrc2:src
0:00:00.360145387  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link udpsrc2:src and manager:recv_rtcp_sink_0
0:00:00.360273355  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked udpsrc2:src and manager:recv_rtcp_sink_0, successful
0:00:00.360333043  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.360393668  1051  0x1fb31b0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<udpsrc2:src> Received event on flushing pad. Discarding
0:00:00.361282991  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "udpsink"
0:00:00.362169084  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSink@0x6cf3b128> adding pad 'sink'
0:00:00.363808042  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "fakesrc"
0:00:00.364479083  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSrc@0x6cf3e1f8> adding pad 'src'
0:00:00.364840281  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element fakesrc0:src to element udpsink0:sink
0:00:00.364920489  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad fakesrc0:src
0:00:00.364992937  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad udpsink0:sink
0:00:00.365066322  1051  0x1fb31b0 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: fakesrc0 and udpsink0 in same bin, no need for ghost pads
0:00:00.365179708  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link fakesrc0:src and udpsink0:sink
0:00:00.365265697  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked fakesrc0:src and udpsink0:sink, successful
0:00:00.365325541  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.365390385  1051  0x1fb31b0 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<fakesrc0:src> Received event on flushing pad. Discarding
0:00:00.366255541  1051  0x1fb31b0 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "udpsink"
0:00:00.366418509  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSink@0x6cf40508> adding pad 'sink'
0:00:00.367996842  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink1> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.368131217  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink1> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.368244811  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink1> continue state change READY to PAUSED, final PLAYING
0:00:00.368363405  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink1> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.368509186  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink1> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.368603352  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink1> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.368672050  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsink1> completed state change to PLAYING
0:00:00.368747207  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.368937623  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad udpsink1:sink
0:00:00.369037258  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'send_rtcp_src_0' in element "manager"
0:00:00.369149186  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'send_rtcp_src' in element "rtpsession0"
0:00:00.369366165  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpsession0> adding pad 'send_rtcp_src'
0:00:00.369679237  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpsession0:send_rtcp_src and send_rtcp_src_0:proxypad2
0:00:00.369771269  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpsession0:send_rtcp_src and send_rtcp_src_0:proxypad2, successful
0:00:00.369833352  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.369961633  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<manager> adding pad 'send_rtcp_src_0'
0:00:00.370094706  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link manager:send_rtcp_src_0 and udpsink1:sink
0:00:00.370180435  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked manager:send_rtcp_src_0 and udpsink1:sink, successful
0:00:00.370236685  1051  0x1fb31b0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.370490435  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsink0> completed state change to NULL
0:00:00.370570383  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<fakesrc0> completed state change to NULL
0:00:00.370701633  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink0> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.370781633  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink0> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.370899654  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink0> continue state change READY to PAUSED, final PLAYING
0:00:00.371010435  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink0> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.371141424  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink0> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.371255278  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink0> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.371324862  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsink0> completed state change to PLAYING
0:00:00.371399393  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.371517883  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<fakesrc0> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.371595955  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesrc0> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.371704810  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<fakesrc0> continue state change READY to PAUSED, final PLAYING
0:00:00.371877778  1051  0x1fb31b0 INFO                 basesrc gstbasesrc.c:1358:gst_base_src_do_seek:<fakesrc0> seeking: bytes segment start=0, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0, base=0, position 0, duration -1
0:00:00.372015799  1051  0x1fb31b0 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x6cf1ede4 on task 0x1fb4e10
0:00:00.372081268  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<fakesrc0:src> created task 0x1fb4e10
0:00:00.372490955  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<fakesrc0> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.372578091  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesrc0> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.372704184  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<fakesrc0> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.372775382  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<fakesrc0> completed state change to PLAYING
0:00:00.372852674  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesrc0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.372917882  1051 0x6cf0ab20 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'sink' in element "fakesrc0"
0:00:00.373210069  1051 0x6cf0ab20 FIXME                default gstutils.c:3981:gst_pad_create_stream_id_internal:<fakesrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id
0:00:00.373851892  1051 0x6cf0ab20 INFO               GST_EVENT gstevent.c:895:gst_event_new_segment: creating segment event bytes segment start=0, offset=0, stop=-1, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0, base=0, position 0, duration -1
0:00:00.374062621  1051 0x6cf0ab20 INFO                 basesrc gstbasesrc.c:2945:gst_base_src_loop:<fakesrc0> marking pending DISCONT
0:00:00.374862204  1051 0x6cf0ab20 INFO                 basesrc gstbasesrc.c:2839:gst_base_src_loop:<fakesrc0> pausing after gst_base_src_get_range() = eos
0:00:00.374982100  1051 0x6cf0ab20 INFO                    task gsttask.c:316:gst_task_func:<fakesrc0:src> Task going to paused
0:00:00.389688917  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpssrcdemux0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.389817876  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpssrcdemux0> completed state change to PLAYING
0:00:00.389896522  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpssrcdemux0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.390052876  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpssrcdemux0' changed state to 4(PLAYING) successfully
0:00:00.390154699  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpstorage0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.390227511  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpstorage0> completed state change to PLAYING
0:00:00.390302303  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpstorage0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.390421573  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpstorage0' changed state to 4(PLAYING) successfully
0:00:00.390519490  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpsession0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.390826730  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpsession0> completed state change to PLAYING
0:00:00.390909750  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpsession0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.391035323  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpsession0' changed state to 4(PLAYING) successfully
0:00:00.391131886  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel0> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.391205584  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel0> completed state change to PLAYING
0:00:00.391280948  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.391399750  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel0' changed state to 4(PLAYING) successfully
0:00:00.391493604  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel1> current PAUSED pending VOID_PENDING, desired next PLAYING
0:00:00.391622563  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel1> completed state change to PLAYING
0:00:00.391700271  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.391820427  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel1' changed state to 4(PLAYING) successfully
0:00:00.391904125  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<manager> completed state change to PLAYING
0:00:00.391980948  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<manager> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.392189594  1051  0x1fb31b0 INFO                 basesrc gstbasesrc.c:1358:gst_base_src_do_seek:<udpsrc1> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.392328083  1051  0x1fb31b0 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x1f96d94 on task 0x1fb4eb8
0:00:00.392394125  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<udpsrc1:src> created task 0x1fb4eb8
0:00:00.392730010  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsrc1> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.392816364  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc1> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.392917250  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsrc1> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.392919906  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'sink' in element "udpsrc1"
0:00:00.393155114  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc1> completed state change to PLAYING
0:00:00.393239749  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc1> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.393433551  1051  0x1fb31b0 INFO                 basesrc gstbasesrc.c:1358:gst_base_src_do_seek:<udpsrc2> seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.393559176  1051  0x1fb31b0 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x1f96eec on task 0x1fb4f60
0:00:00.393625583  1051  0x1fb31b0 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<udpsrc2:src> created task 0x1fb4f60
0:00:00.393977093  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsrc2> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.394125791  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc2> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.394246260  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsrc2> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.394299489  1051 0x6cf0ab80 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event application/x-rtp, media=(string)video, payload=(int)96, clock-rate=(int)90000, encoding-name=(string)H265, sprop-vps=(string)"QAEMAf//AWAAAAMAsAAAAwAAAwB7vAwAAAMABAAAAwA+qA\=\=", sprop-sps=(string)QgEBAWAAAAMAsAAAAwAAAwB7oAPAgBDljb5JMvzcBAQEEAAAAwAQAAADAPoQ, sprop-pps=(string)"RAHA8vA8kA\=\=", a-type=(string)broadcast, a-tool=(string)"RTSP\ Streaming\ Media", x-qt-text-nam=(string)"session\ descriped", x-qt-text-inf=(string)1, x-broadcastcontrol=(string)TIME, x-copyright=(string)"\ RTSP", a-recvonly=(string)"", a-framerate=(string)15, x-framerate=(string)15, ssrc=(uint)562215218, clock-base=(uint)149962860, seqnum-base=(uint)0, npt-start=(guint64)0, play-speed=(double)1, play-scale=(double)1
0:00:00.394325322  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc2> completed state change to PLAYING
0:00:00.394476937  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc2> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.394915686  1051 0x6cf0abb0 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'sink' in element "udpsrc2"
0:00:00.395369697  1051 0x6cf0abb0 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event application/x-rtcp
0:00:00.440673013  1051 0x6cf0ab80 INFO               GST_EVENT gstevent.c:895:gst_event_new_segment: creating segment event time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x00, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999
0:00:00.440939680  1051 0x6cf0ab80 INFO                 basesrc gstbasesrc.c:2945:gst_base_src_loop:<udpsrc1> marking pending DISCONT
0:00:00.444146710  1051 0x6cf0ab80 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event application/x-rtp, media=(string)video, payload=(int)96, clock-rate=(int)90000, encoding-name=(string)H265, sprop-vps=(string)"QAEMAf//AWAAAAMAsAAAAwAAAwB7vAwAAAMABAAAAwA+qA\=\=", sprop-sps=(string)QgEBAWAAAAMAsAAAAwAAAwB7oAPAgBDljb5JMvzcBAQEEAAAAwAQAAADAPoQ, sprop-pps=(string)"RAHA8vA8kA\=\=", a-type=(string)broadcast, a-tool=(string)"RTSP\ Streaming\ Media", x-qt-text-nam=(string)"session\ descriped", x-qt-text-inf=(string)1, x-broadcastcontrol=(string)TIME, x-copyright=(string)"\ RTSP", a-recvonly=(string)"", a-framerate=(string)15, x-framerate=(string)15, ssrc=(uint)562215218, clock-base=(uint)149962860, seqnum-base=(uint)0, npt-start=(guint64)0, play-speed=(double)1, play-scale=(double)1
0:00:00.444338637  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpssrcdemux0> adding pad 'src_562215218'
0:00:00.444431710  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpssrcdemux0> adding pad 'rtcp_src_562215218'
0:00:00.444557491  1051 0x6cf0ab80 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "rtpjitterbuffer"
0:00:00.445850199  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRtpJitterBuffer@0x1fda378> adding pad 'src'
0:00:00.445940876  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRtpJitterBuffer@0x1fda378> adding pad 'sink'
0:00:00.446050303  1051 0x6cf0ab80 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: creating element "rtpptdemux"
0:00:00.446692698  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstRtpPtDemux@0x1fdc800> adding pad 'sink'
0:00:00.447209417  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element rtpjitterbuffer0:src to element rtpptdemux0:sink
0:00:00.447290511  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpjitterbuffer0:src
0:00:00.447364990  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpptdemux0:sink
0:00:00.447434729  1051 0x6cf0ab80 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: rtpjitterbuffer0 and rtpptdemux0 in same bin, no need for ghost pads
0:00:00.447538271  1051 0x6cf0ab80 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpjitterbuffer0:src and rtpptdemux0:sink
0:00:00.447635875  1051 0x6cf0ab80 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpjitterbuffer0:src and rtpptdemux0:sink, successful
0:00:00.447695094  1051 0x6cf0ab80 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.447762542  1051 0x6cf0ab80 INFO               GST_EVENT gstpad.c:5808:gst_pad_send_event_unchecked:<rtpjitterbuffer0:src> Received event on flushing pad. Discarding
0:00:00.447888167  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtpptdemux0> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.447967073  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpptdemux0> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.448116031  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtpptdemux0> continue state change READY to PAUSED, final PLAYING
0:00:00.448224208  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtpptdemux0> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.448304729  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpptdemux0> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.448422958  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtpptdemux0> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.448493739  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpptdemux0> completed state change to PLAYING
0:00:00.448569885  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpptdemux0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.448760979  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtpjitterbuffer0> committing state from NULL to READY, pending PLAYING, next PAUSED
0:00:00.448840927  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpjitterbuffer0> notifying about state-changed NULL to READY (PLAYING pending)
0:00:00.448958427  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtpjitterbuffer0> continue state change READY to PAUSED, final PLAYING
0:00:00.449412906  1051 0x6cf0ab80 INFO                    task gsttask.c:457:gst_task_set_lock: setting stream lock 0x6cf3c6ec on task 0x6cf42418
0:00:00.449488374  1051 0x6cf0ab80 INFO                GST_PADS gstpad.c:6154:gst_pad_start_task:<rtpjitterbuffer0:src> created task 0x6cf42418
0:00:00.449824572  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtpjitterbuffer0> committing state from READY to PAUSED, pending PLAYING, next PLAYING
0:00:00.449919051  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpjitterbuffer0> notifying about state-changed READY to PAUSED (PLAYING pending)
0:00:00.450046135  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtpjitterbuffer0> continue state change PAUSED to PLAYING, final PLAYING
0:00:00.450133062  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpjitterbuffer0> completed state change to PLAYING
0:00:00.450217020  1051 0x6cf0ab80 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpjitterbuffer0> notifying about state-changed PAUSED to PLAYING (VOID_PENDING pending)
0:00:00.450336655  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpssrcdemux0:src_562215218
0:00:00.450414884  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpjitterbuffer0:sink
0:00:00.450524103  1051 0x6cf0ab80 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpssrcdemux0:src_562215218 and rtpjitterbuffer0:sink
0:00:00.450615874  1051 0x6cf0ab80 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpssrcdemux0:src_562215218 and rtpjitterbuffer0:sink, successful
0:00:00.450674155  1051 0x6cf0ab80 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.450880822  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad rtpssrcdemux0:rtcp_src_562215218
0:00:00.450962072  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:917:gst_element_get_static_pad: no such pad 'sink_rtcp' in element "rtpjitterbuffer0"
0:00:00.451184311  1051 0x6cf0ab80 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpjitterbuffer0> adding pad 'sink_rtcp'
0:00:00.451302280  1051 0x6cf0ab80 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpssrcdemux0:rtcp_src_562215218 and rtpjitterbuffer0:sink_rtcp
0:00:00.451389728  1051 0x6cf0ab80 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpssrcdemux0:rtcp_src_562215218 and rtpjitterbuffer0:sink_rtcp, successful
0:00:00.451502853  1051 0x6cf0ab80 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.452298842  1051 0x6cf0ab80 INFO         rtpjitterbuffer rtpjitterbuffer.c:778:rtp_jitter_buffer_calculate_pts: resync to time 0:00:00.266942870, rtptime 0:27:46.374000000
0:00:00.452945873  1051  0x1fbbef0 INFO               GST_EVENT gstevent.c:814:gst_event_new_caps: creating caps event application/x-rtp, media=(string)video, payload=(int)96, clock-rate=(int)90000, encoding-name=(string)H265, sprop-vps=(string)"QAEMAf//AWAAAAMAsAAAAwAAAwB7vAwAAAMABAAAAwA+qA\=\=", sprop-sps=(string)QgEBAWAAAAMAsAAAAwAAAwB7oAPAgBDljb5JMvzcBAQEEAAAAwAQAAADAPoQ, sprop-pps=(string)"RAHA8vA8kA\=\=", a-type=(string)broadcast, a-tool=(string)"RTSP\ Streaming\ Media", x-qt-text-nam=(string)"session\ descriped", x-qt-text-inf=(string)1, x-broadcastcontrol=(string)TIME, x-copyright=(string)"\ RTSP", a-recvonly=(string)"", a-framerate=(string)15, x-framerate=(string)15, ssrc=(uint)562215218, clock-base=(uint)149962860, seqnum-base=(uint)0, npt-start=(guint64)0, play-speed=(double)1, play-scale=(double)1
0:00:00.453096602  1051  0x1fbbef0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<rtpptdemux0> adding pad 'src_96'
0:00:00.453445925  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link rtpptdemux0:src_96 and recv_rtp_src_0_562215218_96:proxypad3
0:00:00.453545300  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked rtpptdemux0:src_96 and recv_rtp_src_0_562215218_96:proxypad3, successful
0:00:00.453607748  1051  0x1fbbef0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.453845769  1051  0x1fbbef0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<manager> adding pad 'recv_rtp_src_0_562215218_96'
0:00:00.454204310  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link manager:recv_rtp_src_0_562215218_96 and recv_rtp_src_0_562215218_96:proxypad4
0:00:00.454295039  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:2586:gst_pad_link_full: linked manager:recv_rtp_src_0_562215218_96 and recv_rtp_src_0_562215218_96:proxypad4, successful
0:00:00.454356914  1051  0x1fbbef0 INFO               GST_EVENT gstevent.c:1517:gst_event_new_reconfigure: creating reconfigure event
0:00:00.454584623  1051  0x1fbbef0 INFO        GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<source> adding pad 'recv_rtp_src_0_562215218_96'
0:00:00.454706706  1051  0x1fbbef0 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad depay:sink
-2020 12:53:29:934.690 GMT] writeHeaderCallback(): RequestId: 969a22b6-78cc-4d96-b8b6-77f80881013e
[DEBUG] [29-04-2020 12:53:29:935.282 GMT] describeStreamCurlHandler(): DescribeStream API response: {"StreamInfo":{"CreationTime":1.586210606267E9,"DataRetentionInHours":1,"DeviceName":"Kinesis_Video_Device","KmsKeyId":"arn:aws:kms:us-west-2:zzzzzzzzzz:alias/aws/kinesisvideo","MediaType":"video/h264","Status":"ACTIVE","StreamARN":"arn:aws:kinesisvideo:us-west-2:zzzzzzzzzz:stream/xxxxx-stream/yyyyyyyy","StreamName":"xxxxx-stream","Version":"a5TPP3tumlG7Lwer37IW"}}
[INFO ] [29-04-2020 12:53:29:944.195 GMT] describeStreamResultEvent(): Describe stream result event.
[WARN ] [29-04-2020 12:53:29:944.518 GMT] describeStreamResult(): Retention period returned from the DescribeStream call doesn't match the one specified in the StreamInfo
[DEBUG] [29-04-2020 12:53:29:944.628 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000020
[INFO ] [29-04-2020 12:53:31:036.226 GMT] writeHeaderCallback(): RequestId: 9b9632a0-7a55-4fbd-bc6e-b65b52423565
[DEBUG] [29-04-2020 12:53:31:036.602 GMT] getStreamingEndpointCurlHandler(): GetStreamingEndpoint API response: {"DataEndpoint":"https://s-aaaaa.kinesisvideo.us-west-2.amazonaws.com"}
[INFO ] [29-04-2020 12:53:31:045.826 GMT] getStreamingEndpointResultEvent(): Get streaming endpoint result event.
[DEBUG] [29-04-2020 12:53:31:046.086 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000020, Next state: 0x0000000000000010
[DEBUG] [29-04-2020 12:53:31:046.188 GMT] getStreamingTokenHandler invoked
[DEBUG] [29-04-2020 12:53:31:046.335 GMT] Refreshing credentials. Force refreshing: 1 Now time is: 1588164811046283203 Expiration: 1588168408
[INFO ] [29-04-2020 12:53:31:046.426 GMT] New credentials expiration is 1588168411
[INFO ] [29-04-2020 12:53:31:046.618 GMT] getStreamingTokenResultEvent(): Get streaming token result event.
[DEBUG] [29-04-2020 12:53:31:046.764 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [29-04-2020 12:53:31:046.861 GMT] streamReadyHandler invoked
[DEBUG] [29-04-2020 12:53:31:047.388 GMT] Stream is ready
[INFO ] [29-04-2020 12:53:31:153.608 GMT] Streaming from rtsp source
New pad found: recv_rtp_src_0_562215218_96
0:00:00.455035872  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link source:recv_rtp_src_0_562215218_96 and depay:sink
0:00:00.455272070  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:2434:gst_pad_link_prepare: caps are incompatible
0:00:00.455365768  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:2529:gst_pad_link_full: link between source:recv_rtp_src_0_562215218_96 and depay:sink failed: no common format
0:00:00.455852070  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<source:recv_rtp_src_0_562215218_96> pad has no peer
0:00:00.455988737  1051  0x1fbbef0 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<source:recv_rtp_src_0_562215218_96> pad has no peer
0:00:00.456179466  1051  0x1fbbef0 INFO                    task gsttask.c:316:gst_task_func:<rtpjitterbuffer0:src> Task going to paused
0:00:00.521901681  1051 0x6cf0ab80 INFO                 basesrc gstbasesrc.c:2965:gst_base_src_loop:<udpsrc1> pausing after gst_pad_push() = not-linked
0:00:00.522063191  1051 0x6cf0ab80 WARN                 basesrc gstbasesrc.c:3055:gst_base_src_loop:<udpsrc1> error: Internal data stream error.
0:00:00.522133243  1051 0x6cf0ab80 WARN                 basesrc gstbasesrc.c:3055:gst_base_src_loop:<udpsrc1> error: streaming stopped, reason not-linked (-1)
0:00:00.522287410  1051 0x6cf0ab80 INFO        GST_ERROR_SYSTEM gstelement.c:2145:gst_element_message_full_with_details:<udpsrc1> posting message: Internal data stream error.
0:00:00.522478087  1051 0x6cf0ab80 INFO        GST_ERROR_SYSTEM gstelement.c:2172:gst_element_message_full_with_details:<udpsrc1> posted error message: Internal data stream error.
Error received from element udpsrc1: Internal data stream error.
Debugging information: gstbasesrc.c(3055): gst_base_src_loop (): /GstPipeline:rtsp-kinesis-pipeline/GstRTSPSrc:source/GstUDPSrc:udpsrc1:
streaming stopped, reason not-linked (-1)
0:00:00.522735691  1051 0x6cf0ab80 INFO                    task gsttask.c:316:gst_task_func:<udpsrc1:src> Task going to paused
0:00:00.522929962  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<appsink> current READY pending PAUSED, desired next READY
0:00:00.523123087  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<appsink> completed state change to READY
0:00:00.523206472  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<appsink> notifying about state-changed READY to READY (VOID_PENDING pending)
0:00:00.523313295  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'appsink' changed state to 2(READY) successfully
0:00:00.523409441  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h264parse> current PLAYING pending VOID_PENDING, desired next READY
0:00:00.523500014  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<h264parse> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:00.523577305  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h264parse> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:00.523672409  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<h264parse> continue state change PAUSED to READY, final READY
0:00:00.524065951  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h264parse> completed state change to READY
0:00:00.524148972  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h264parse> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.524251524  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'h264parse' changed state to 2(READY) successfully
0:00:00.524348242  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filter> current PLAYING pending VOID_PENDING, desired next READY
0:00:00.524434544  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<filter> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:00.524510221  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filter> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:00.524606680  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<filter> continue state change PAUSED to READY, final READY
0:00:00.524710221  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<filter> completed state change to READY
0:00:00.524787409  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filter> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.524887305  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'filter' changed state to 2(READY) successfully
0:00:00.524976680  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<depay> current PLAYING pending VOID_PENDING, desired next READY
0:00:00.525068034  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<depay> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:00.525189961  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<depay> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:00.525285742  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<depay> continue state change PAUSED to READY, final READY
0:00:00.525387252  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<depay> completed state change to READY
0:00:00.525464909  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<depay> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.525564492  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'depay' changed state to 2(READY) successfully
0:00:00.525655221  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<source> current PLAYING pending VOID_PENDING, desired next READY
0:00:00.525908086  1051  0x1fb31b0 INFO                    task gsttask.c:316:gst_task_func:<task0> Task going to paused
0:00:00.526005586  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsink1' changed state to 3(PAUSED) successfully
0:00:00.526103190  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsink0' changed state to 3(PAUSED) successfully
0:00:00.526201367  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'manager' changed state to 3(PAUSED) successfully
0:00:00.526289283  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'fakesrc0' changed state to 3(PAUSED) successfully
0:00:00.526376471  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsrc1' changed state to 3(PAUSED) successfully
0:00:00.526461887  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsrc2' changed state to 3(PAUSED) successfully
0:00:00.526680117  1051  0x1fb31b0 INFO                    task gsttask.c:318:gst_task_func:<task0> Task resume from paused
0:00:00.526683242  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<source> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:00.526836366  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<source> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:00.526936835  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<source> continue state change PAUSED to READY, final READY
0:00:00.527149960  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsink1' changed state to 2(READY) successfully
0:00:00.527245585  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsink0' changed state to 2(READY) successfully
0:00:00.527342252  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'manager' changed state to 2(READY) successfully
0:00:00.527476835  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'fakesrc0' changed state to 2(READY) successfully
0:00:00.527561054  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsrc1' changed state to 2(READY) successfully
0:00:00.527645012  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsrc2' changed state to 2(READY) successfully
0:00:00.527780116  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<source> completed state change to READY
0:00:00.527866106  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<source> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.527966626  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'source' changed state to 2(READY) successfully
0:00:00.527991314  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpptdemux0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.528079491  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<rtsp-kinesis-pipeline> committing state from PAUSED to READY, pending NULL, next NULL
0:00:00.528105845  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpptdemux0> completed state change to PAUSED
0:00:00.528164908  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtsp-kinesis-pipeline> notifying about state-changed PAUSED to READY (NULL pending)
0:00:00.528224751  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpptdemux0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.528320012  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<rtsp-kinesis-pipeline> continue state change READY to NULL, final NULL
0:00:00.528387355  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpptdemux0' changed state to 3(PAUSED) successfully
0:00:00.528449491  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<appsink> current READY pending VOID_PENDING, desired next NULL
0:00:00.528488033  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpjitterbuffer0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.528566366  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpjitterbuffer0> completed state change to PAUSED
0:00:00.528566001  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<appsink> completed state change to NULL
0:00:00.528649126  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpjitterbuffer0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.528710793  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<appsink> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.528799439  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2997:gst_bin_change_state_func:<manager> child 'rtpjitterbuffer0' changed state to 3(PAUSED) successfully without preroll
0:00:00.528900480  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'appsink' changed state to 1(NULL) successfully
0:00:00.528951157  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpssrcdemux0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.528995480  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<h264parse> current READY pending VOID_PENDING, desired next NULL
0:00:00.529024699  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpssrcdemux0> completed state change to PAUSED
0:00:00.529088657  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<h264parse> completed state change to NULL
0:00:00.529172980  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<h264parse> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.529190949  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpssrcdemux0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.529276053  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'h264parse' changed state to 1(NULL) successfully
0:00:00.529337199  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpssrcdemux0' changed state to 3(PAUSED) successfully
0:00:00.529369022  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<filter> current READY pending VOID_PENDING, desired next NULL
0:00:00.529440897  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpstorage0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.529509803  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<filter> completed state change to NULL
0:00:00.529547876  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpstorage0> completed state change to PAUSED
0:00:00.529610376  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<filter> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.529626470  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpstorage0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.529716209  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'filter' changed state to 1(NULL) successfully
0:00:00.529775845  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpstorage0' changed state to 3(PAUSED) successfully
0:00:00.529805636  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<depay> current READY pending VOID_PENDING, desired next NULL
0:00:00.529884907  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpsession0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.529977980  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<depay> completed state change to NULL
0:00:00.530049959  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpsession0> completed state change to PAUSED
0:00:00.530056730  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<depay> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.530133865  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpsession0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.530222303  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'depay' changed state to 1(NULL) successfully
0:00:00.530281782  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpsession0' changed state to 3(PAUSED) successfully
0:00:00.530312667  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<source> current READY pending VOID_PENDING, desired next NULL
0:00:00.530384646  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel0> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.530491053  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel0> completed state change to PAUSED
0:00:00.530507667  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsink1' changed state to 1(NULL) successfully
0:00:00.530573240  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel0> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.530653188  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsink0' changed state to 1(NULL) successfully
0:00:00.530716625  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel0' changed state to 3(PAUSED) successfully
0:00:00.530809750  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel1> current PLAYING pending VOID_PENDING, desired next PAUSED
0:00:00.530881209  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel1> completed state change to PAUSED
0:00:00.530957198  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel1> notifying about state-changed PLAYING to PAUSED (VOID_PENDING pending)
0:00:00.531059438  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel1' changed state to 3(PAUSED) successfully
0:00:00.531153917  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<manager> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:00.531230792  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<manager> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:00.531365375  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<manager> continue state change PAUSED to READY, final READY
0:00:00.531598448  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpptdemux0> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.531758656  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpptdemux0> completed state change to READY
0:00:00.531836729  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpptdemux0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.531990167  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpptdemux0' changed state to 2(READY) successfully
0:00:00.532130010  1051  0x1fbbef0 INFO                    task gsttask.c:318:gst_task_func:<rtpjitterbuffer0:src> Task resume from paused
0:00:00.532450687  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpjitterbuffer0> completed state change to READY
0:00:00.532532458  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpjitterbuffer0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.532637510  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpjitterbuffer0' changed state to 2(READY) successfully
0:00:00.532735166  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpssrcdemux0> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.532912718  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpssrcdemux0> removing pad 'src_562215218'
0:00:00.533004645  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpssrcdemux0:src_562215218(0x6cf3c3f0) and rtpjitterbuffer0:sink(0x6cf3c7f8)
0:00:00.533114385  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpssrcdemux0:src_562215218 and rtpjitterbuffer0:sink
0:00:00.533247770  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpssrcdemux0> removing pad 'rtcp_src_562215218'
0:00:00.533341312  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpssrcdemux0:rtcp_src_562215218(0x6cf3c548) and rtpjitterbuffer0:sink_rtcp(0x6cf3caa8)
0:00:00.533444645  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpssrcdemux0:rtcp_src_562215218 and rtpjitterbuffer0:sink_rtcp
0:00:00.533565895  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpssrcdemux0> completed state change to READY
0:00:00.533645374  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpssrcdemux0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.533749385  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpssrcdemux0' changed state to 2(READY) successfully
0:00:00.533926989  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpptdemux0> current READY pending VOID_PENDING, desired next READY
0:00:00.534001051  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2623:gst_bin_element_set_state:<rtpptdemux0> skipping transition from READY to  READY
0:00:00.534078343  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpptdemux0' changed state to 2(READY) successfully
0:00:00.534165374  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpjitterbuffer0> current READY pending VOID_PENDING, desired next READY
0:00:00.534235218  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2623:gst_bin_element_set_state:<rtpjitterbuffer0> skipping transition from READY to  READY
0:00:00.534312301  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpjitterbuffer0' changed state to 2(READY) successfully
0:00:00.534406676  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpssrcdemux0> current READY pending VOID_PENDING, desired next READY
0:00:00.534477093  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2623:gst_bin_element_set_state:<rtpssrcdemux0> skipping transition from READY to  READY
0:00:00.534554332  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpssrcdemux0' changed state to 2(READY) successfully
0:00:00.534644280  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpstorage0> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.534771676  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpstorage0> completed state change to READY
0:00:00.534850113  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpstorage0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.534954280  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpstorage0' changed state to 2(READY) successfully
0:00:00.535052301  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpsession0> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.535249124  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpsession0> completed state change to READY
0:00:00.535329228  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpsession0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.535433707  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpsession0' changed state to 2(READY) successfully
0:00:00.535524332  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel0> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.535660374  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel0> completed state change to READY
0:00:00.535738499  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel0> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.535897301  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel0' changed state to 2(READY) successfully
0:00:00.535988446  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel1> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.536107144  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel1> completed state change to READY
0:00:00.536185321  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.536289332  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel1' changed state to 2(READY) successfully
0:00:00.536467300  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<manager> completed state change to READY
0:00:00.536662925  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<manager> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.536792457  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsrc1> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:00.536801363  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'manager' changed state to 1(NULL) successfully
0:00:00.536877352  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc1> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:00.536951154  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'fakesrc0' changed state to 1(NULL) successfully
0:00:00.537013238  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsrc1> continue state change PAUSED to READY, final READY
0:00:00.537173706  1051 0x6cf0ab80 INFO                    task gsttask.c:318:gst_task_func:<udpsrc1:src> Task resume from paused
0:00:00.537441571  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc1> completed state change to READY
0:00:00.537523550  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.537642560  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsrc2> committing state from PLAYING to PAUSED, pending READY, next READY
0:00:00.537654227  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsrc1' changed state to 1(NULL) successfully
0:00:00.537726467  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc2> notifying about state-changed PLAYING to PAUSED (READY pending)
0:00:00.537858758  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsrc2> continue state change PAUSED to READY, final READY
0:00:00.538071519  1051 0x6cf0abb0 INFO                 basesrc gstbasesrc.c:2839:gst_base_src_loop:<udpsrc2> pausing after gst_base_src_get_range() = flushing
0:00:00.538302091  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc2> completed state change to READY
0:00:00.538384643  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc2> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.538513550  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<source> child 'udpsrc2' changed state to 1(NULL) successfully
0:00:00.538749487  1051  0x1fb31b0 WARN                 rtspsrc gstrtspsrc.c:5995:gst_rtspsrc_try_send:<source> send interrupted
0:00:00.538816414  1051  0x1fb31b0 WARN                 rtspsrc gstrtspsrc.c:7669:gst_rtspsrc_close:<source> TEARDOWN interrupted
0:00:00.539269695  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc1> completed state change to NULL
0:00:00.539354174  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc1> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.539492299  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking udpsrc1:src(0x1f96d48) and manager:recv_rtp_sink_0(0x6cf37090)
0:00:00.539607924  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked udpsrc1:src and manager:recv_rtp_sink_0
0:00:00.539703185  1051  0x1fb31b0 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<source> removed child "udpsrc1"
0:00:00.539906726  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink0> committing state from PLAYING to PAUSED, pending NULL, next READY
0:00:00.539987872  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink0> notifying about state-changed PLAYING to PAUSED (NULL pending)
0:00:00.540087820  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink0> continue state change PAUSED to READY, final NULL
0:00:00.540246361  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink0> committing state from PAUSED to READY, pending NULL, next NULL
0:00:00.540327403  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink0> notifying about state-changed PAUSED to READY (NULL pending)
0:00:00.540423132  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink0> continue state change READY to NULL, final NULL
0:00:00.540504851  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsink0> completed state change to NULL
0:00:00.540582768  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.540704018  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking fakesrc0:src(0x6cf1ed98) and udpsink0:sink(0x6cf1ec40)
0:00:00.540809799  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked fakesrc0:src and udpsink0:sink
0:00:00.541017715  1051  0x1fb31b0 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<source> removed child "udpsink0"
0:00:00.541220059  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsrc2> completed state change to NULL
0:00:00.541299851  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsrc2> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.541420632  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking udpsrc2:src(0x1f96ea0) and manager:recv_rtcp_sink_0(0x6cf37208)
0:00:00.541529590  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked udpsrc2:src and manager:recv_rtcp_sink_0
0:00:00.541622351  1051  0x1fb31b0 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<source> removed child "udpsrc2"
0:00:00.541796621  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink1> committing state from PLAYING to PAUSED, pending NULL, next READY
0:00:00.541875840  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink1> notifying about state-changed PLAYING to PAUSED (NULL pending)
0:00:00.541971882  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink1> continue state change PAUSED to READY, final NULL
0:00:00.542117507  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<udpsink1> committing state from PAUSED to READY, pending NULL, next NULL
0:00:00.542196100  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink1> notifying about state-changed PAUSED to READY (NULL pending)
0:00:00.542290632  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<udpsink1> continue state change READY to NULL, final NULL
0:00:00.542371517  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<udpsink1> completed state change to NULL
0:00:00.542447767  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<udpsink1> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.542569121  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking manager:send_rtcp_src_0(0x6cf37380) and udpsink1:sink(0x6cf3c140)
0:00:00.542676152  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked manager:send_rtcp_src_0 and udpsink1:sink
0:00:00.542777506  1051  0x1fb31b0 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<source> removed child "udpsink1"
0:00:00.542907767  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<fakesrc0> committing state from PLAYING to PAUSED, pending NULL, next READY
0:00:00.542987038  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesrc0> notifying about state-changed PLAYING to PAUSED (NULL pending)
0:00:00.543081360  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<fakesrc0> continue state change PAUSED to READY, final NULL
0:00:00.543241829  1051 0x6cf0ab20 INFO                    task gsttask.c:318:gst_task_func:<fakesrc0:src> Task resume from paused
0:00:00.543422558  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2651:gst_element_continue_state:<fakesrc0> committing state from PAUSED to READY, pending NULL, next NULL
0:00:00.543502923  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesrc0> notifying about state-changed PAUSED to READY (NULL pending)
0:00:00.543599277  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2658:gst_element_continue_state:<fakesrc0> continue state change READY to NULL, final NULL
0:00:00.543678287  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<fakesrc0> completed state change to NULL
0:00:00.543753548  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<fakesrc0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.543853548  1051  0x1fb31b0 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<source> removed child "fakesrc0"
0:00:00.543970266  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<source> removing pad 'recv_rtp_src_0_562215218_96'
0:00:00.544075683  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking manager:recv_rtp_src_0_562215218_96(0x6cf37670) and recv_rtp_src_0_562215218_96:proxypad4(0x1f86d38)
0:00:00.544183704  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked manager:recv_rtp_src_0_562215218_96 and recv_rtp_src_0_562215218_96:proxypad4
0:00:00.544450214  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpptdemux0> current READY pending VOID_PENDING, desired next NULL
0:00:00.544547714  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpptdemux0> removing pad 'src_96'
0:00:00.544639693  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpptdemux0:src_96(0x6cf3ceb0) and recv_rtp_src_0_562215218_96:proxypad3(0x1f86bd0)
0:00:00.544745162  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpptdemux0:src_96 and recv_rtp_src_0_562215218_96:proxypad3
0:00:00.544870943  1051  0x1fb31b0 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<manager> removing pad 'recv_rtp_src_0_562215218_96'
0:00:00.544989849  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpptdemux0> completed state change to NULL
0:00:00.545070318  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpptdemux0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.545176985  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpptdemux0' changed state to 1(NULL) successfully
0:00:00.545314745  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpptdemux0> current NULL pending VOID_PENDING, desired next NULL
0:00:00.545388860  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2623:gst_bin_element_set_state:<rtpptdemux0> skipping transition from NULL to  NULL
0:00:00.545504485  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpptdemux0' changed state to 1(NULL) successfully
0:00:00.545594901  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpjitterbuffer0> current READY pending VOID_PENDING, desired next NULL
0:00:00.545686568  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpjitterbuffer0> completed state change to NULL
0:00:00.545765422  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpjitterbuffer0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.545869953  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpjitterbuffer0' changed state to 1(NULL) successfully
0:00:00.545971880  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpssrcdemux0> current READY pending VOID_PENDING, desired next NULL
0:00:00.546060213  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpssrcdemux0> completed state change to NULL
0:00:00.546137766  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpssrcdemux0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.546239536  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpssrcdemux0' changed state to 1(NULL) successfully
0:00:00.546332505  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpstorage0> current READY pending VOID_PENDING, desired next NULL
0:00:00.546418911  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpstorage0> completed state change to NULL
0:00:00.546589901  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpstorage0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.546707192  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpstorage0' changed state to 1(NULL) successfully
0:00:00.546832088  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<rtpsession0> current READY pending VOID_PENDING, desired next NULL
0:00:00.546928442  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpsession0> completed state change to NULL
0:00:00.547005057  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtpsession0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.547107401  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'rtpsession0' changed state to 1(NULL) successfully
0:00:00.547200213  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel0> current READY pending VOID_PENDING, desired next NULL
0:00:00.547288807  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel0> completed state change to NULL
0:00:00.547400630  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel0> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.547503963  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel0' changed state to 1(NULL) successfully
0:00:00.547594952  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2506:gst_bin_element_set_state:<funnel1> current READY pending VOID_PENDING, desired next NULL
0:00:00.547681723  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<funnel1> completed state change to NULL
0:00:00.547756619  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<funnel1> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.547857713  1051  0x1fb31b0 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<manager> child 'funnel1' changed state to 1(NULL) successfully
0:00:00.547957140  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<manager> completed state change to NULL
0:00:00.548033025  1051  0x1fb31b0 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<manager> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.548182296  1051  0x1fb31b0 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<source> removed child "manager"
0:00:00.548667973  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<source> completed state change to NULL
0:00:00.548753858  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<source> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.548864379  1051  0x1e89e00 INFO              GST_STATES gstbin.c:2954:gst_bin_change_state_func:<rtsp-kinesis-pipeline> child 'source' changed state to 1(NULL) successfully
0:00:00.549125004  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<fakesrc0> 0x6cf3e1f8 dispose
0:00:00.549199431  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<fakesrc0> removing pad 'src'
0:00:00.549293129  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<fakesrc0> 0x6cf3e1f8 parent class dispose
0:00:00.549370056  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<fakesrc0> 0x6cf3e1f8 finalize
0:00:00.549438910  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<fakesrc0> 0x6cf3e1f8 finalize parent
0:00:00.549523546  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<udpsink1> 0x6cf40508 dispose
0:00:00.549590785  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<udpsink1> removing pad 'sink'
0:00:00.549677243  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<udpsink1> 0x6cf40508 parent class dispose
0:00:00.549822243  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<udpsink1> 0x6cf40508 finalize
0:00:00.549936514  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<udpsink1> 0x6cf40508 finalize parent
0:00:00.550029952  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<udpsink0> 0x6cf3b128 dispose
0:00:00.550099379  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<udpsink0> removing pad 'sink'
0:00:00.550186358  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<udpsink0> 0x6cf3b128 parent class dispose
0:00:00.550308441  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<udpsink0> 0x6cf3b128 finalize
0:00:00.550378962  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<udpsink0> 0x6cf3b128 finalize parent
0:00:00.550489483  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<udpsrc2> 0x6cf1c780 dispose
0:00:00.550556983  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<udpsrc2> removing pad 'src'
0:00:00.550642972  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<udpsrc2> 0x6cf1c780 parent class dispose
0:00:00.550722035  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<udpsrc2> 0x6cf1c780 finalize
0:00:00.550789899  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<udpsrc2> 0x6cf1c780 finalize parent
0:00:00.550886201  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<udpsrc1> 0x6cf1c418 dispose
0:00:00.550953962  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<udpsrc1> removing pad 'src'
0:00:00.551038910  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<udpsrc1> 0x6cf1c418 parent class dispose
0:00:00.551133128  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<udpsrc1> 0x6cf1c418 finalize
0:00:00.551201305  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<udpsrc1> 0x6cf1c418 finalize parent
0:00:00.551343337  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpssrcdemux0> completed state change to NULL
0:00:00.551417711  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpsession0> completed state change to NULL
0:00:00.551511566  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpsession0> removing pad 'recv_rtp_sink'
0:00:00.551600055  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking funnel0:src(0x6cf1e430) and rtpsession0:recv_rtp_sink(0x6cf1e6e0)
0:00:00.551713180  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked funnel0:src and rtpsession0:recv_rtp_sink
0:00:00.551822243  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpsession0> removing pad 'recv_rtp_src'
0:00:00.551910888  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpsession0:recv_rtp_src(0x6cf1e838) and rtpstorage0:sink(0x6cf1e2d8)
0:00:00.552048545  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpsession0:recv_rtp_src and rtpstorage0:sink
0:00:00.552198649  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<manager> removing pad 'recv_rtp_sink_0'
0:00:00.552299586  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking recv_rtp_sink_0:proxypad0(0x1f86630) and funnel0:funnelpad0(0x6cf36088)
0:00:00.552386409  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked recv_rtp_sink_0:proxypad0 and funnel0:funnelpad0
0:00:00.552481826  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<manager> removing pad 'recv_rtcp_sink_0'
0:00:00.552576826  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking recv_rtcp_sink_0:proxypad1(0x1f86798) and funnel1:funnelpad1(0x6cf361e8)
0:00:00.552660992  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked recv_rtcp_sink_0:proxypad1 and funnel1:funnelpad1
0:00:00.552761253  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpsession0> removing pad 'recv_rtcp_sink'
0:00:00.552849638  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking funnel1:src(0x6cf1e588) and rtpsession0:recv_rtcp_sink(0x6cf1e990)
0:00:00.552951357  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked funnel1:src and rtpsession0:recv_rtcp_sink
0:00:00.553056825  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpsession0> removing pad 'sync_src'
0:00:00.553145367  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpsession0:sync_src(0x6cf1eae8) and rtpssrcdemux0:rtcp_sink(0x1f96bf0)
0:00:00.553257971  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpsession0:sync_src and rtpssrcdemux0:rtcp_sink
0:00:00.553404534  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<manager> removing pad 'send_rtcp_src_0'
0:00:00.553501929  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpsession0:send_rtcp_src(0x6cf3c298) and send_rtcp_src_0:proxypad2(0x1f86900)
0:00:00.553604013  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpsession0:send_rtcp_src and send_rtcp_src_0:proxypad2
0:00:00.553729065  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpsession0> removing pad 'send_rtcp_src'
0:00:00.553841773  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<manager> removed child "rtpsession0"
0:00:00.553979221  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpstorage0:src(0x6cf1e180) and rtpssrcdemux0:sink(0x6cf1e028)
0:00:00.554081200  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpstorage0:src and rtpssrcdemux0:sink
0:00:00.554186148  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<manager> removed child "rtpssrcdemux0"
0:00:00.554351773  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpptdemux0> completed state change to NULL
0:00:00.554430054  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtpjitterbuffer0> completed state change to NULL
0:00:00.554537085  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking rtpjitterbuffer0:src(0x6cf3c6a0) and rtpptdemux0:sink(0x6cf3c950)
0:00:00.554644221  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked rtpjitterbuffer0:src and rtpptdemux0:sink
0:00:00.554745366  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<manager> removed child "rtpjitterbuffer0"
0:00:00.554854898  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<manager> removed child "rtpptdemux0"
0:00:00.554979429  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<manager> removed child "rtpstorage0"
0:00:00.555087554  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<manager> removed child "funnel1"
0:00:00.555206148  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<manager> removed child "funnel0"
0:00:00.555301616  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<manager> 0x6cf260a8 dispose
0:00:00.555373387  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<manager> 0x6cf260a8 parent class dispose
0:00:00.555465783  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<manager> 0x6cf260a8 finalize
0:00:00.555536356  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<manager> 0x6cf260a8 finalize parent
0:00:00.555620575  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<funnel1> removing pad 'funnelpad1'
0:00:00.555706929  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<funnel1> 0x6cf33190 dispose
0:00:00.555776981  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<funnel1> removing pad 'src'
0:00:00.555870210  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<funnel1> 0x6cf33190 parent class dispose
0:00:00.555941824  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<funnel1> 0x6cf33190 finalize
0:00:00.556009845  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<funnel1> 0x6cf33190 finalize parent
0:00:00.556090678  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<funnel0> removing pad 'funnelpad0'
0:00:00.556175053  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<funnel0> 0x6cf330c8 dispose
0:00:00.556242710  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<funnel0> removing pad 'src'
0:00:00.556334376  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<funnel0> 0x6cf330c8 parent class dispose
0:00:00.556437866  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<funnel0> 0x6cf330c8 finalize
0:00:00.556657814  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<funnel0> 0x6cf330c8 finalize parent
0:00:00.556757293  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtpsession0> 0x6cf2c128 dispose
0:00:00.556827449  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtpsession0> 0x6cf2c128 parent class dispose
0:00:00.557046147  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtpsession0> 0x6cf2c128 finalize
0:00:00.557117241  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtpsession0> 0x6cf2c128 finalize parent
0:00:00.557223751  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtpstorage0> 0x6cf33000 dispose
0:00:00.557293074  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpstorage0> removing pad 'src'
0:00:00.557387136  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpstorage0> removing pad 'sink'
0:00:00.557481720  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtpstorage0> 0x6cf33000 parent class dispose
0:00:00.557553438  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtpstorage0> 0x6cf33000 finalize
0:00:00.557622032  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtpstorage0> 0x6cf33000 finalize parent
0:00:00.557710261  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtpssrcdemux0> 0x6cf32008 dispose
0:00:00.557779167  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpssrcdemux0> removing pad 'sink'
0:00:00.557863438  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpssrcdemux0> removing pad 'rtcp_sink'
0:00:00.557950886  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtpssrcdemux0> 0x6cf32008 parent class dispose
0:00:00.558025834  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtpssrcdemux0> 0x6cf32008 finalize
0:00:00.558095417  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtpssrcdemux0> 0x6cf32008 finalize parent
0:00:00.558184271  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtpjitterbuffer0> 0x1fda378 dispose
0:00:00.558258803  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpjitterbuffer0> removing pad 'sink_rtcp'
0:00:00.558351615  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpjitterbuffer0> removing pad 'src'
0:00:00.558442344  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpjitterbuffer0> removing pad 'sink'
0:00:00.558571719  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtpjitterbuffer0> 0x1fda378 parent class dispose
0:00:00.558751511  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtpjitterbuffer0> 0x1fda378 finalize
0:00:00.558824948  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtpjitterbuffer0> 0x1fda378 finalize parent
0:00:00.558903646  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtpptdemux0> 0x1fdc800 dispose
0:00:00.558971927  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<rtpptdemux0> removing pad 'sink'
0:00:00.559058073  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtpptdemux0> 0x1fdc800 parent class dispose
0:00:00.559135000  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtpptdemux0> 0x1fdc800 finalize
0:00:00.559203282  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtpptdemux0> 0x1fdc800 finalize parent
0:00:00.559361250  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2676:gst_element_continue_state:<rtsp-kinesis-pipeline> completed state change to NULL
0:00:00.559443386  1051  0x1e89e00 INFO              GST_STATES gstelement.c:2579:_priv_gst_element_state_changed:<rtsp-kinesis-pipeline> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.559585417  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking h264parse:src(0x1f96940) and appsink:sink(0x1f963e0)
0:00:00.559696042  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked h264parse:src and appsink:sink
0:00:00.559800521  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<rtsp-kinesis-pipeline> removed child "appsink"
0:00:00.559911250  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<appsink> 0x1edb8d0 dispose
0:00:00.559981302  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<appsink> removing pad 'sink'
0:00:00.560069062  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<appsink> 0x1edb8d0 parent class dispose
0:00:00.560184948  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<appsink> 0x1edb8d0 finalize
0:00:00.560255625  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<appsink> 0x1edb8d0 finalize parent
0:00:00.560381562  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking depay:src(0x1f96690) and filter:sink(0x1f96130)
0:00:00.560486146  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked depay:src and filter:sink
0:00:00.560608489  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2134:gst_pad_unlink: unlinking filter:src(0x1f96288) and h264parse:sink(0x1f967e8)
0:00:00.560711093  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstpad.c:2188:gst_pad_unlink: unlinked filter:src and h264parse:sink
0:00:00.560836458  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<rtsp-kinesis-pipeline> removed child "filter"
0:00:00.560949114  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<filter> 0x1edc0a8 dispose
0:00:00.561019583  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<filter> removing pad 'sink'
0:00:00.561105104  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<filter> removing pad 'src'
0:00:00.561190677  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<filter> 0x1edc0a8 parent class dispose
0:00:00.561262499  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<filter> 0x1edc0a8 finalize
0:00:00.561330156  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<filter> 0x1edc0a8 finalize parent
0:00:00.561418177  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<rtsp-kinesis-pipeline> removed child "h264parse"
0:00:00.561513385  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<h264parse> 0x1fb0208 dispose
0:00:00.561583124  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<h264parse> removing pad 'sink'
0:00:00.561669270  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<h264parse> removing pad 'src'
0:00:00.561753853  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<h264parse> 0x1fb0208 parent class dispose
0:00:00.561896353  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<h264parse> 0x1fb0208 finalize
0:00:00.561968593  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<h264parse> 0x1fb0208 finalize parent
0:00:00.562057291  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<rtsp-kinesis-pipeline> removed child "depay"
0:00:00.562151718  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<depay> 0x1fa0070 dispose
0:00:00.562220468  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<depay> removing pad 'sink'
0:00:00.562304114  1051  0x1e89e00 INFO        GST_ELEMENT_PADS gstelement.c:789:gst_element_remove_pad:<depay> removing pad 'src'
0:00:00.562387655  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<depay> 0x1fa0070 parent class dispose
0:00:00.562476509  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<depay> 0x1fa0070 finalize
0:00:00.562544739  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<depay> 0x1fa0070 finalize parent
0:00:00.562644374  1051  0x1e89e00 INFO           GST_PARENTAGE gstbin.c:1801:gst_bin_remove_func:<rtsp-kinesis-pipeline> removed child "source"
0:00:00.562755936  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<source> 0x1faa180 dispose
0:00:00.562826613  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<source> 0x1faa180 parent class dispose
0:00:00.562936613  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtspreal0> 0x1fae020 dispose
0:00:00.563006666  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtspreal0> 0x1fae020 parent class dispose
0:00:00.563094113  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtspreal0> 0x1fae020 finalize
0:00:00.563163332  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtspreal0> 0x1fae020 finalize parent
0:00:00.563236301  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtspwms0> 0x1fa2988 dispose
0:00:00.563304790  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtspwms0> 0x1fa2988 parent class dispose
0:00:00.563378697  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtspwms0> 0x1fa2988 finalize
0:00:00.563447238  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtspwms0> 0x1fa2988 finalize parent
0:00:00.563527238  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<source> 0x1faa180 finalize
0:00:00.563595780  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<source> 0x1faa180 finalize parent
0:00:00.563666353  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3251:gst_element_dispose:<rtsp-kinesis-pipeline> 0x1f860a0 dispose
0:00:00.563856144  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3297:gst_element_dispose:<rtsp-kinesis-pipeline> 0x1f860a0 parent class dispose
0:00:00.563930936  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3328:gst_element_finalize:<rtsp-kinesis-pipeline> 0x1f860a0 finalize
0:00:00.564002290  1051  0x1e89e00 INFO         GST_REFCOUNTING gstelement.c:3334:gst_element_finalize:<rtsp-kinesis-pipeline> 0x1f860a0 finalize parent
[INFO ] [29-04-2020 12:53:31:503.387 GMT] Pad link failed
[INFO ] [29-04-2020 12:53:31:611.975 GMT] stopKinesisVideoStreamSync(): Synchronously stopping Kinesis Video Stream 0000000001e83620.
[DEBUG] [29-04-2020 12:53:31:612.224 GMT] streamClosedHandler invoked for upload handle: 18446744073709551615
[INFO ] [29-04-2020 12:53:31:612.389 GMT] Freeing Kinesis Video Stream xxxxx-stream
[INFO ] [29-04-2020 12:53:31:612.541 GMT] freeKinesisVideoStream(): Freeing Kinesis Video stream.
[DEBUG] [29-04-2020 12:53:31:612.645 GMT] curlApiCallbacksShutdownActiveRequests(): pActiveRequests hashtable is empty
[INFO ] [29-04-2020 12:53:32:013.450 GMT] Freeing Kinesis Video Stream xxxxx-stream
[INFO ] [29-04-2020 12:53:32:013.746 GMT] freeKinesisVideoClient(): Freeing Kinesis Video Client
[DEBUG] [29-04-2020 12:53:32:013.859 GMT] curlApiCallbacksShutdownActiveRequests(): pActiveRequests hashtable is empty
[DEBUG] [29-04-2020 12:53:32:416.102 GMT] freeKinesisVideoClientInternal(): Total allocated memory 0
[WARN ] [29-04-2020 12:53:32:416.367 GMT] curlApiCallbacksShutdown(): curlApiCallbacksShutdown called when already in progress of shutting down
MushMal commented 4 years ago

It's not really clear to me what's causing the TEARDOWN. Seems like the rtsp module. Might need more eyes on it. @chehefen any ideas?

dvsantana commented 4 years ago

From the sample_app, it seems like it looks only for h264 encoding. Could that be the reason?

disa6302 commented 4 years ago

@dvsantana , Have you tried giving video/h265 as the value for content-type?

dvsantana commented 4 years ago

@disa6302 , I have, I also changed the other occurences of 264 to 265 to see if I would get anything different, and I got another error, so maybe it is not allowed

dvsantana commented 4 years ago

This is the error I get when I change every occurrence of 264 to 265 (7 occurrences) in the sample multistream app.

There is a line which might be a problem, that contains: logStreamInfo(): Codec id: V_MPEG4/ISO/AVC

[INFO ] [04-05-2020 00:23:46:062.028 GMT] createKinesisVideoClient(): Creating Kinesis Video Client
[INFO ] [04-05-2020 00:23:46:062.259 GMT] heapInitialize(): Initializing native heap with limit size 134217728, spill ratio 0% and flags 0x00000001
[INFO ] [04-05-2020 00:23:46:062.296 GMT] heapInitialize(): Creating AIV heap.
[INFO ] [04-05-2020 00:23:46:062.377 GMT] heapInitialize(): Heap is initialized OK
[DEBUG] [04-05-2020 00:23:46:062.485 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[DEBUG] [04-05-2020 00:23:46:062.559 GMT] getSecurityTokenHandler invoked
[DEBUG] [04-05-2020 00:23:46:062.660 GMT] Refreshing credentials. Force refreshing: 0 Now time is: 1588551826062609694 Expiration: 0
[INFO ] [04-05-2020 00:23:46:062.725 GMT] New credentials expiration is 1588555426
[DEBUG] [04-05-2020 00:23:46:062.780 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000010
[INFO ] [04-05-2020 00:23:46:062.814 GMT] createDeviceResultEvent(): Create device result event.
[DEBUG] [04-05-2020 00:23:46:062.861 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [04-05-2020 00:23:46:062.895 GMT] clientReadyHandler invoked
[DEBUG] [04-05-2020 00:23:46:062.930 GMT] Client is ready
[INFO ] [04-05-2020 00:23:46:063.033 GMT] Creating Kinesis Video Stream stream-xxxx
[INFO ] [04-05-2020 00:23:46:063.074 GMT] createKinesisVideoStream(): Creating Kinesis Video Stream.
[DEBUG] [04-05-2020 00:23:46:063.108 GMT] logStreamInfo(): Kinesis Video Stream Info
[DEBUG] [04-05-2020 00:23:46:063.130 GMT] logStreamInfo():  Stream name: stream-xxxx 
[DEBUG] [04-05-2020 00:23:46:063.156 GMT] logStreamInfo():  Streaming type: STREAMING_TYPE_REALTIME 
[DEBUG] [04-05-2020 00:23:46:063.179 GMT] logStreamInfo():  Content type: video/h265 
[DEBUG] [04-05-2020 00:23:46:063.204 GMT] logStreamInfo():  Max latency (100ns): 600000000
[DEBUG] [04-05-2020 00:23:46:063.227 GMT] logStreamInfo():  Fragment duration (100ns): 20000000
[DEBUG] [04-05-2020 00:23:46:063.252 GMT] logStreamInfo():  Key frame fragmentation: Yes
[DEBUG] [04-05-2020 00:23:46:063.275 GMT] logStreamInfo():  Use frame timecode: Yes
[DEBUG] [04-05-2020 00:23:46:063.352 GMT] logStreamInfo():  Absolute frame timecode: Yes
[DEBUG] [04-05-2020 00:23:46:063.437 GMT] logStreamInfo():  Nal adaptation flags: 0
[DEBUG] [04-05-2020 00:23:46:063.504 GMT] logStreamInfo():  Average bandwith (bps): 4194304
[DEBUG] [04-05-2020 00:23:46:063.571 GMT] logStreamInfo():  Framerate: 25
[DEBUG] [04-05-2020 00:23:46:063.637 GMT] logStreamInfo():  Buffer duration (100ns): 1200000000
[DEBUG] [04-05-2020 00:23:46:063.704 GMT] logStreamInfo():  Replay duration (100ns): 400000000
[DEBUG] [04-05-2020 00:23:46:063.771 GMT] logStreamInfo():  Connection Staleness duration (100ns): 600000000
[DEBUG] [04-05-2020 00:23:46:063.839 GMT] logStreamInfo():  Store Pressure Policy: 1
[DEBUG] [04-05-2020 00:23:46:063.905 GMT] logStreamInfo():  View Overflow Policy: 1
[DEBUG] [04-05-2020 00:23:46:063.981 GMT] logStreamInfo():  Segment UUID: NULL
[DEBUG] [04-05-2020 00:23:46:064.049 GMT] logStreamInfo():  Frame ordering mode: 0
[DEBUG] [04-05-2020 00:23:46:064.115 GMT] logStreamInfo(): Track list
[DEBUG] [04-05-2020 00:23:46:064.160 GMT] logStreamInfo():  Track id: 1
[DEBUG] [04-05-2020 00:23:46:064.225 GMT] logStreamInfo():  Track name: kinesis_video
[DEBUG] [04-05-2020 00:23:46:064.290 GMT] logStreamInfo():  Codec id: V_MPEG4/ISO/AVC
[DEBUG] [04-05-2020 00:23:46:064.357 GMT] logStreamInfo():  Track type: TRACK_INFO_TYPE_VIDEO
[DEBUG] [04-05-2020 00:23:46:064.422 GMT] logStreamInfo():  Track cpd: NULL
[DEBUG] [04-05-2020 00:23:46:064.660 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002
[INFO ] [04-05-2020 00:23:47:087.514 GMT] writeHeaderCallback(): RequestId: afbde1b4-8129-4129-8b65-c6bb31bc5c36
[DEBUG] [04-05-2020 00:23:47:087.954 GMT] describeStreamCurlHandler(): DescribeStream API response: {"StreamInfo":{"CreationTime":1.586210606267E9,"DataRetentionInHours":1,"DeviceName":"Kinesis_Video_Device","KmsKeyId":"arn:aws:kms:us-west-2:yyyyy:alias/aws/kinesisvideo","MediaType":"video/h264","Status":"ACTIVE","StreamARN":"arn:aws:kinesisvideo:us-west-2:yyyyy:stream/stream-xxxx/aaaaaaa","StreamName":"stream-xxxx","Version":"a5TPP3tumlG7Lwer37IW"}}
[INFO ] [04-05-2020 00:23:47:097.630 GMT] describeStreamResultEvent(): Describe stream result event.
[WARN ] [04-05-2020 00:23:47:097.891 GMT] describeStreamResult(): Retention period returned from the DescribeStream call doesn't match the one specified in the StreamInfo
[WARN ] [04-05-2020 00:23:47:098.115 GMT] describeStreamResult(): Content type returned from the DescribeStream call doesn't match the one specified in the StreamInfo
[DEBUG] [04-05-2020 00:23:47:098.427 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000020
[INFO ] [04-05-2020 00:23:48:121.377 GMT] writeHeaderCallback(): RequestId: 044469e3-38cb-4675-ba69-0cf64f74bb29
[DEBUG] [04-05-2020 00:23:48:121.669 GMT] getStreamingEndpointCurlHandler(): GetStreamingEndpoint API response: {"DataEndpoint":"https://s-aaaaaaaa.kinesisvideo.us-west-2.amazonaws.com"}
[INFO ] [04-05-2020 00:23:48:130.868 GMT] getStreamingEndpointResultEvent(): Get streaming endpoint result event.
[DEBUG] [04-05-2020 00:23:48:131.052 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000020, Next state: 0x0000000000000010
[DEBUG] [04-05-2020 00:23:48:131.135 GMT] getStreamingTokenHandler invoked
[DEBUG] [04-05-2020 00:23:48:131.252 GMT] Refreshing credentials. Force refreshing: 1 Now time is: 1588551828131202097 Expiration: 1588555426
[INFO ] [04-05-2020 00:23:48:131.385 GMT] New credentials expiration is 1588555428
[INFO ] [04-05-2020 00:23:48:131.624 GMT] getStreamingTokenResultEvent(): Get streaming token result event.
[DEBUG] [04-05-2020 00:23:48:131.832 GMT] stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000040
[DEBUG] [04-05-2020 00:23:48:131.977 GMT] streamReadyHandler invoked
[DEBUG] [04-05-2020 00:23:48:132.437 GMT] Stream is ready: stream-xxxx
 GST_ELEMENT_FACTORY gstelementfactory.c:359:gst_element_factory_create: creating element "pipeline" named "rtsp-kinesis-pipeline"
[DEBUG] [04-05-2020 00:59:40:991.398 GMT] appsink configured
0:00:02.272951672 23976   0xd35c00 INFO        GST_ELEMENT_PADS gstutils.c:1774:gst_element_link_pads_full: trying to link element depay:(any) to element encoder_filter:(any)
0:00:02.273065578 23976   0xd35c00 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link depay:src and encoder_filter:sink
0:00:02.273249638 23976   0xd35c00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<encoder_filter:src> pad has no peer
0:00:02.273504583 23976   0xd35c00 INFO        GST_ELEMENT_PADS gstelement.c:920:gst_element_get_static_pad: found pad encoder_filter:sink
0:00:02.273615728 23976   0xd35c00 INFO                GST_PADS gstutils.c:1588:prepare_link_maybe_ghosting: depay and encoder_filter in same bin, no need for ghost pads
0:00:02.273734477 23976   0xd35c00 INFO                GST_PADS gstpad.c:2378:gst_pad_link_prepare: trying to link depay:src and encoder_filter:sink
0:00:02.273837288 23976   0xd35c00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<encoder_filter:src> pad has no peer
0:00:02.273921350 23976   0xd35c00 INFO                GST_PADS gstpad.c:2434:gst_pad_link_prepare: caps are incompatible
0:00:02.274006245 23976   0xd35c00 INFO                GST_PADS gstpad.c:2529:gst_pad_link_full: link between depay:src and encoder_filter:sink failed: no common format
0:00:02.274141296 23976   0xd35c00 INFO                GST_PADS gstutils.c:1035:gst_pad_check_link: trying to link depay:src and encoder_filter:sink
0:00:02.274227128 23976   0xd35c00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<encoder_filter:src> pad has no peer
0:00:02.274342179 23976   0xd35c00 INFO                GST_PADS gstpad.c:4232:gst_pad_peer_query:<encoder_filter:src> pad has no peer
0:00:02.274527333 23976   0xd35c00 INFO        GST_ELEMENT_PADS gstutils.c:1227:gst_element_get_compatible_pad:<depay> Could not find a compatible pad to link to encoder_filter
Elements could not be linked.
[INFO ] [04-05-2020 00:23:48:187.630 GMT] Freeing Kinesis Video Stream stream-xxxx
[INFO ] [04-05-2020 00:23:48:187.826 GMT] freeKinesisVideoStream(): Freeing Kinesis Video stream.
[DEBUG] [04-05-2020 00:23:48:187.925 GMT] curlApiCallbacksShutdownActiveRequests(): pActiveRequests hashtable is empty
[INFO ] [04-05-2020 00:23:48:588.353 GMT] Freeing Kinesis Video Stream stream-xxxx
[INFO ] [04-05-2020 00:23:48:588.462 GMT] freeKinesisVideoClient(): Freeing Kinesis Video Client
[DEBUG] [04-05-2020 00:23:48:588.533 GMT] curlApiCallbacksShutdownActiveRequests(): pActiveRequests hashtable is empty
[DEBUG] [04-05-2020 00:23:48:990.681 GMT] freeKinesisVideoClientInternal(): Total allocated memory 0
[WARN ] [04-05-2020 00:23:48:990.884 GMT] curlApiCallbacksShutdown(): curlApiCallbacksShutdown called when already in progress of shutting down
dvsantana commented 4 years ago

The stream-format was causing the issue, it seems. For this, I switched the capsfilter to:

        GstCaps *h265_caps = gst_caps_new_simple("video/x-h265",
                                                 "stream-format", G_TYPE_STRING, "hvc1", //or hev1 or byte-stream
                                                 "alignment", G_TYPE_STRING, "au",
                                                 NULL);

Will run a few more tests and will close the issue if everything works as it should.

disa6302 commented 4 years ago

Sure @dvsantana ! Thanks.

dvsantana commented 4 years ago

With the following line in the GST_DEBUG=4

0:00:57.043961846 2061 0xbcbef0 FIXME rtph265depay gstrtph265depay.c:1278:gst_rtp_h265_depay_process:<depay> Assuming DONL field is not present

From this, there is no support for hvc1. But when I use the other possibilities, which are hev1 and byte-stream, I get an error as well, as if it is not supported.

Does anyone know any fix?

chehefen commented 4 years ago

rtph265depay should support hvc1 as described in its template:

GObject
 +----GInitiallyUnowned
       +----GstObject
             +----GstElement
                   +----GstRTPBaseDepayload
                         +----GstRtpH265Depay

Pad Templates:
  SINK template: 'sink'
    Availability: Always
    Capabilities:
      application/x-rtp
                  media: video
             clock-rate: 90000
          encoding-name: H265

  SRC template: 'src'
    Availability: Always
    Capabilities:
      video/x-h265
          stream-format: hvc1
              alignment: au
      video/x-h265
          stream-format: byte-stream
              alignment: { (string)nal, (string)au }
dvsantana commented 4 years ago

@chehefen yes, that's where I got it from, but I'm still getting that FIXME. Should I just ignore it? It looks like the stream is transmitting.

zhiyua-git commented 4 years ago

Hi @dvsantana ,

From your previous log, seems you were hitting ERROR ACK max fragment duration exceeded, which means your stream doesn't provide I-frame for 10 seconds. Can you check if you can tune the rtsp source or through the gstreamer pipeline to generate I-frame more often? Thanks.

dvsantana commented 4 years ago

@zhiyua-git , I've fixed that already, but it sure was the problem in the previous log, thanks for noticing. Now I'm able to send the stream, however, I'm still getting that FIXME. It doesn't seem to affect the stream since I'm getting all the confirmations on the logs: 

[DEBUG] [04-05-2020 22:57:02:465.016 GMT] postReadCallback(): Wrote 61149 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [04-05-2020 22:57:02:768.620 GMT] postReadCallback(): Wrote 65524 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [04-05-2020 22:57:03:085.066 GMT] postReadCallback(): Wrote 40095 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [04-05-2020 22:57:03:317.636 GMT] postReadCallback(): Wrote 65524 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [04-05-2020 22:57:05:805.983 GMT] postReadCallback(): Wrote 65524 bytes to Kinesis Video. Upload stream handle: 0
[DEBUG] [04-05-2020 22:57:06:542.113 GMT] Kinesis Video client and stream metrics
    >> Overall storage byte size: 134217728
    >> Available storage byte size: 132060775
    >> Allocated storage byte size: 2156953
    >> Total view allocation byte size: 144080
    >> Total streams frame rate (fps): 14
    >> Total streams transfer rate (bps): 13491080 (13174 Kbps)
    >> Current view duration (ms): 3002
    >> Overall view duration (ms): 5162
    >> Current view byte size: 1575304
    >> Overall view byte size: 2155153
    >> Current frame rate (fps): 14.7956
    >> Current transfer rate (bps): 13491080 (13174 Kbps)
[DEBUG] [04-05-2020 22:57:07:444.277 GMT] postReadCallback(): Wrote 65524 bytes to Kinesis Video. Upload stream handle: 0

Also, I'm not able to see it in the KVS console, but that was expected as it says it only allows H264, or in my application, but that is probably my fault (it was working with H264).

zhiyua-git commented 4 years ago

@dvsantana , you will need to also update the codec id https://github.com/awslabs/amazon-kinesis-video-streams-producer-sdk-cpp/blob/824de900c2d4b42a403319ace5de9d68ec88b171/kinesis-video-gst-demo/kinesis_video_gstreamer_sample_app.cpp#L46 to "V_MPEGH/ISO/HEVC" as backend relies on it to check if it is h264 or h265. And you can try to verify the playback on https://aws-samples.github.io/amazon-kinesis-video-streams-media-viewer/.

dvsantana commented 4 years ago

to "V_MPEGH/ISO/HEVC" as backend relies on it to check if it is h264 or h265. And you can try to verify the playback on https://aws-samples.github.io/amazon-kinesis-video-streams-media-viewer/.

@zhiyua-git I changed it, the FIXME is still happening 0:00:57.043961846 2061 0xbcbef0 FIXME rtph265depay gstrtph265depay.c:1278:gst_rtp_h265_depay_process:<depay> Assuming DONL field is not present

To verify that playback, do I need to be on a specific browser? It only shows the loading symbol, and the logs say that it is streaming

dvsantana commented 4 years ago

Isn't this supposed to be working? Or am I doing something wrong?

image

zhiyua-git commented 4 years ago

You can switch different combinations of streaming protocols and players, some of them might not support h265 well.

dvsantana commented 4 years ago

Tried them all, the only one that got close to working was:

image

zhiyua-git commented 4 years ago

Can you specify env var KVS_DEBUG_DUMP_DATA_FILE_DIR to a directory and rerun the app, then check the output mkv to see if it is playable in VLC player? If it plays just fine, please send a short one to Kinesis-video-support@amazon.com so we can take a close look into it to understand what is failing. Thanks.

dvsantana commented 4 years ago

@zhiyua-git thank you so much for your help!

I was able to see the mkv on the VLC player, so I sent the output mkv to the email above.

MixMasterMitch commented 4 years ago

@dvsantana H.265 playback is not supported in Chrome. We put your MKV to a stream and viewed it in Safari via the Media Stream Viewer test page without issue.

However, if I take the HLS URL and paste it directly into the Safari URL bar, it does not play.

A helpful debugging tool is Apple's mediastreamvalidator. It revealed a couple things:

Error: Unsupported HEVC profile_space
--> Detail:  profile_space: 1 ('A')
--> Source:  https://b-647daf39.kinesisvideo.us-west-2.amazonaws.com/hls/v1/getHLSMasterPlaylist.m3u8
--> Compare: getHLSMediaPlaylist.m3u8?TrackNumber=1

^ I am not sure why this is a problem since the media is able to be decoded.

Error: Playlist vs segment duration mismatch
--> Detail:  Segment duration 0.9930, Playlist duration: 3.0660
--> Source:  getHLSMediaPlaylist.m3u8?TrackNumber=1 - getMP4MediaFragment.mp4?FragmentNumber=91343852333200022166869999398375715807955315381&TrackNumber=1

^I don't know how the segment duration is being calculated by Apple, but I can see that the frame timecodes are not at a consistent interval, so that is probably causing the Apple tool to have issues.

dvsantana commented 4 years ago

@MixMasterMitch, thank you so much for your answer, it cleared things a bit here. I tried in different browsers, but for the safari I had to use the iOS safari, so that could be the reason why I couldn't get it to work.

As for the other issues I don't know how the segment and the playlist could have different duration, but I don't think that is a main issue.

Again, thank you all for taking your time and helping me, I learned a lot on the way. I will close this issue now, as the main problem was resolved already.