VST recording issue

Accelerated Computing Intelligent Video Analytics Metropolis Microservices for Jetson
1

Hello Nvidia,

I am testing VST microservice on AGX Orin 64GB.
I use
POST http://192.168.1.30:30080/vst/api/v1/record/82f390aa-8b95-4f01-89a3-9dde1b2d4795/event api call to record 5 seconds event video. It takes more then 1.5 minute to record it. Is it expected behaviour?

[2024-11-28T15:11:14.650Z:281471470136288:HttpServerRequestHandler.cpp:172: handle]	uri:/api/v1/record/82f390aa-8b95-4f01-89a3-9dde1b2d4795/event
[2024-11-28T15:11:14.650Z:281471470136288:HttpServerRequestHandler.cpp:173: handle]	method:POST
[2024-11-28T15:11:14.650Z:281471470136288:streamrecorder.cpp:251: onEvent]	Handle Event for camera id = 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:11:14.650Z:281471470136288:VideoQueue.cpp:98: dropExtraFrames]	Q size After drop: 50 and oldest frame ts = 1732806672654
[2024-11-28T15:11:14.650Z:281471470136288:gstmux.cpp:980: onEvent]	Handling event for 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:11:14.780Z:281466906733536:gstmux.cpp:1290: setPlayState]	Transitioning Pipeline into PLAYING State for camera ID = 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:11:14.781Z:281466906733536:gstmux.cpp:1311: setPlayState]	GST_STATE_CHANGE_ASYNC (for PLAYING state) for camera ID = 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:11:14.795Z:281466906733536:gstmux.cpp:691: insertRowInDB]	[Success:] Insert into Database for file /root/store/video/82f390aa-8b95-4f01-89a3-9dde1b2d4795/1280x720/2024/11/28/16/1732806672815.mkv with timestamp : Thu Nov 28 15:11:12 2024

[2024-11-28T15:11:14.795Z:281466906733536:storage_management.cpp:487: addFileInProtectList]	Added file into the in protect list filePath:/root/store/video/82f390aa-8b95-4f01-89a3-9dde1b2d4795/1280x720/2024/11/28/16/1732806672815.mkv removeOrAdd:1
[2024-11-28T15:11:17.798Z:281466889825248:gstmux.cpp:947: event_probe]	Initial condition
[2024-11-28T15:11:17.798Z:281466889825248:gstmux.cpp:948: event_probe]	Resolution = 1280 x 720
[2024-11-28T15:11:17.798Z:281466889825248:gstmux.cpp:949: event_probe]	Framerate = 0 / 0
[2024-11-28T15:11:17.798Z:281466889825248:gstmux.cpp:950: event_probe]	Stream Format = hvc1
[2024-11-28T15:11:18.798Z:281466906733536:gstmux.cpp:113: RecorderQos]	RecorderQos::RecorderQos
[2024-11-28T15:11:18.798Z:281466906733536:gstmux.cpp:130: RecorderQos]	Recording-qos started at:./webroot/qos/recording_qos_2024-11-28T15:11:18Z.csv
[2024-11-28T15:12:11.387Z:281467166714848:fps_display.cpp:80: displayFPS]	Unique ID = recording_82f390aa-8b95-4f01-89a3-9dde1b2d4795 FPS = { 24.971322, 25.075300, 24.849387, 24.994737, 25.048542, 24.886436, 25.180583, 25.052356, 24.905192, 24.938171, 25.103198, 24.889815 }
[2024-11-28T15:12:54.811Z:281466906733536:gstmux.cpp:477: muxerProcessThread]	Stopping recording on event for 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:12:54.811Z:281466906733536:gstmux.cpp:1411: sendEOS]	Sending EOS in MUX pipeline for camera id = 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:12:54.811Z:281466915187680:gstmux.cpp:814: busWatchFunc]	GST_MESSAGE_ASYNC_DONE for camera ID = 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:12:54.818Z:281466906733536:gstmux.cpp:191: updateDbRow]	Success: Update Database with duration 3961 and FPS = 25 for file /root/store/video/82f390aa-8b95-4f01-89a3-9dde1b2d4795/1280x720/2024/11/28/16/1732806672815.mkv with timestamp : Thu Nov 28 15:11:12 2024

[2024-11-28T15:12:54.818Z:281466906733536:storage_management.cpp:487: addFileInProtectList]	Added file into the in protect list filePath:/root/store/video/82f390aa-8b95-4f01-89a3-9dde1b2d4795/1280x720/2024/11/28/16/1732806672815.mkv removeOrAdd:0
[2024-11-28T15:12:54.821Z:281466906733536:gstmux.cpp:1379: setNULLState]	Transitioning Pipeline into NULL State for camera ID = 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:12:54.822Z:281466906733536:gstmux.cpp:1395: setNULLState]	State change to NULL success for camera ID = 82f390aa-8b95-4f01-89a3-9dde1b2d4795
[2024-11-28T15:13:12.357Z:281467166714848:fps_display.cpp:80: displayFPS]	Unique ID = recording_82f390aa-8b95-4f01-89a3-9dde1b2d4795 FPS = { 25.028192, 25.030189, 24.970130, 25.019061, 24.825502, 25.033919, 25.003031, 24.941407, 25.020650, 24.916432, 25.146312, 25.080309 }
[2024-11-28T15:14:13.261Z:281467166714848:fps_display.cpp:80: displayFPS]	Unique ID = recording_82f390aa-8b95-4f01-89a3-9dde1b2d4795 FPS = { 24.998901, 24.868737, 24.868347, 25.133799, 24.897332, 24.992676, 25.053130, 25.006937, 24.908162, 25.084099, 24.981977, 24.867791 }

If I record movie manually using start/stop calls and ~5 seconds between them I get very short movie that contains a few frames, I reduced resolution from 1920x1080 to 1280x768, seems it does not help to reduce recording time. Only if I reduce duration of recording it linearly reduces recording time. For example 10 seconds movie recording takes ~3+minutes, 5 seconds movie 1.5+minutes

Could you please assist?

3

I will check and feedback later.

4

I can’t reproduce the issue in my side. Below is the log for 10 seconds event recording. Can you share the camera setting of your stream? such as resolution/video codec format and fps.

[2024-12-4T6:55:46.622Z:281470731938784:HttpServerRequestHandler.cpp:172: handle]       uri:/api/v1/record/6df44797-acf5-4270-b8a7-dd63b6d16113/event
[2024-12-4T6:55:46.622Z:281470731938784:HttpServerRequestHandler.cpp:173: handle]       method:POST
[2024-12-4T6:55:46.622Z:281470731938784:streamrecorder.cpp:251: onEvent]        Handle Event for camera id = 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:46.622Z:281470731938784:VideoQueue.cpp:98: dropExtraFrames]     Q size After drop: 300 and oldest frame ts = 1733295341629
[2024-12-4T6:55:46.622Z:281470731938784:gstmux.cpp:980: onEvent]        Handling event for 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:46.991Z:281467309386720:gstmux.cpp:1290: setPlayState]  Transitioning Pipeline into PLAYING State for camera ID = 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:46.992Z:281467309386720:gstmux.cpp:1311: setPlayState]  GST_STATE_CHANGE_ASYNC (for PLAYING state) for camera ID = 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:46.999Z:281467309386720:gstmux.cpp:691: insertRowInDB]  [Success:] Insert into Database for file /root/store/video/6df44797-acf5-4270-b8a7-dd63b6d16113/1920x1080/2024/12/04/7/1733295341963.mkv with timestamp : Wed Dec  4 06:55:41 2024

[2024-12-4T6:55:47.0Z:281467309386720:storage_management.cpp:487: addFileInProtectList] Added file into the in protect list filePath:/root/store/video/6df44797-acf5-4270-b8a7-dd63b6d16113/1920x1080/2024/12/04/7/1733295341963.mkv removeOrAdd:1
[2024-12-4T6:55:50.9Z:281466696952800:gstmux.cpp:947: event_probe]      Initial condition
[2024-12-4T6:55:50.9Z:281466696952800:gstmux.cpp:948: event_probe]      Resolution = 1920 x 1080
[2024-12-4T6:55:50.9Z:281466696952800:gstmux.cpp:949: event_probe]      Framerate = 30000 / 1001
[2024-12-4T6:55:50.9Z:281466696952800:gstmux.cpp:950: event_probe]      Stream Format = avc
[2024-12-4T6:55:50.10Z:281467317840864:gstmux.cpp:814: busWatchFunc]    GST_MESSAGE_ASYNC_DONE for camera ID = 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:53.611Z:281467561765856:fps_display.cpp:80: displayFPS] Unique ID = recording_6df44797-acf5-4270-b8a7-dd63b6d16113 FPS = { 60.170726, 59.893221, 59.944286, 59.948833, 59.960797, 59.958480, 59.964523, 59.892971, 59.967656, 59.968181, 59.928479, 59.956998 }
[2024-12-4T6:55:59.966Z:281467309386720:gstmux.cpp:477: muxerProcessThread]     Stopping recording on event for 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:59.966Z:281467309386720:gstmux.cpp:1411: sendEOS]       Sending EOS in MUX pipeline for camera id = 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:59.977Z:281467309386720:gstmux.cpp:191: updateDbRow]    Success: Update Database with duration 9993 and FPS = 60 for file /root/store/video/6df44797-acf5-4270-b8a7-dd63b6d16113/1920x1080/2024/12/04/7/1733295341963.mkv with timestamp : Wed Dec  4 06:55:41 2024

[2024-12-4T6:55:59.977Z:281467309386720:storage_management.cpp:487: addFileInProtectList]       Added file into the in protect list filePath:/root/store/video/6df44797-acf5-4270-b8a7-dd63b6d16113/1920x1080/2024/12/04/7/1733295341963.mkv removeOrAdd:0
[2024-12-4T6:55:59.984Z:281467309386720:gstmux.cpp:1379: setNULLState]  Transitioning Pipeline into NULL State for camera ID = 6df44797-acf5-4270-b8a7-dd63b6d16113
[2024-12-4T6:55:59.985Z:281467309386720:gstmux.cpp:1395: setNULLState]  State change to NULL success for camera ID = 6df44797-acf5-4270-b8a7-dd63b6d16113
5

Hello Kesong,

Thank you for feedback, that the most scary one that I expected.

Here is stream params:

ffprobe -hide_banner -show_streams -show_format  rtsp://192.168.1.30:8554/live/6db998de-96d0-468e-ad2e-e8dd36621f36

Input #0, rtsp, from 'rtsp://192.168.1.30:8554/live/6db998de-96d0-468e-ad2e-e8dd36621f36':
  Metadata:
    title           : LIVE555 Streaming Media v2023.07.24
    comment         : LIVE555 Streaming Media v2023.07.24
  Duration: N/A, start: 0.053600, bitrate: N/A
  Stream #0:0: Video: h264 (Main), yuvj420p(pc, bt709, progressive), 1920x1080, 25 fps, 25 tbr, 90k tbn, 180k tbc
  Stream #0:1: Audio: pcm_alaw, 8000 Hz, 1 channels, s16, 64 kb/s

[STREAM]
index=0
codec_name=h264
codec_long_name=H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
profile=Main
codec_type=video
codec_tag_string=[0][0][0][0]
codec_tag=0x0000
width=1920
height=1080
coded_width=1920
coded_height=1080
closed_captions=0
has_b_frames=0
sample_aspect_ratio=N/A
display_aspect_ratio=N/A
pix_fmt=yuvj420p
level=42
color_range=pc
color_space=bt709
color_transfer=bt709
color_primaries=bt709
chroma_location=left
field_order=progressive
refs=1
is_avc=false
nal_length_size=0
id=N/A
r_frame_rate=25/1
avg_frame_rate=25/1
time_base=1/90000
start_pts=4824
start_time=0.053600
duration_ts=N/A
duration=N/A
bit_rate=N/A
max_bit_rate=N/A
bits_per_raw_sample=8
nb_frames=N/A
nb_read_frames=N/A
nb_read_packets=N/A
DISPOSITION:default=0
DISPOSITION:dub=0
DISPOSITION:original=0
DISPOSITION:comment=0
DISPOSITION:lyrics=0
DISPOSITION:karaoke=0
DISPOSITION:forced=0
DISPOSITION:hearing_impaired=0
DISPOSITION:visual_impaired=0
DISPOSITION:clean_effects=0
DISPOSITION:attached_pic=0
DISPOSITION:timed_thumbnails=0
[/STREAM]
[STREAM]
index=1
codec_name=pcm_alaw
codec_long_name=PCM A-law / G.711 A-law
profile=unknown
codec_type=audio
codec_tag_string=[0][0][0][0]
codec_tag=0x0000
sample_fmt=s16
sample_rate=8000
channels=1
channel_layout=unknown
bits_per_sample=8
id=N/A
r_frame_rate=0/0
avg_frame_rate=0/0
time_base=1/8000
start_pts=N/A
start_time=N/A
duration_ts=N/A
duration=N/A
bit_rate=64000
max_bit_rate=N/A
bits_per_raw_sample=N/A
nb_frames=N/A
nb_read_frames=N/A
nb_read_packets=N/A
DISPOSITION:default=0
DISPOSITION:dub=0
DISPOSITION:original=0
DISPOSITION:comment=0
DISPOSITION:lyrics=0
DISPOSITION:karaoke=0
DISPOSITION:forced=0
DISPOSITION:hearing_impaired=0
DISPOSITION:visual_impaired=0
DISPOSITION:clean_effects=0
DISPOSITION:attached_pic=0
DISPOSITION:timed_thumbnails=0
[/STREAM]
[FORMAT]
filename=rtsp://192.168.1.30:8554/live/6db998de-96d0-468e-ad2e-e8dd36621f36
nb_streams=2
nb_programs=0
format_name=rtsp
format_long_name=RTSP input
start_time=0.053600
duration=N/A
size=N/A
bit_rate=N/A
probe_score=100
TAG:title=LIVE555 Streaming Media v2023.07.24
TAG:comment=LIVE555 Streaming Media v2023.07.24
[/FORMAT]
6

If I understand it correctly VST is not open source project, so I can not debug it by myself. Correct?

7

Yes, VST isn’t open source yet.

8

Finally I got access to a camera of other manufacturer and got VST working as expected:

[2024-12-9T13:3:41.760Z:281471788772320:HttpServerRequestHandler.cpp:172: handle]	uri:/api/v1/record/99da38ad-5d75-4525-95d7-d202b2f96c3e/event
[2024-12-9T13:3:41.760Z:281471788772320:HttpServerRequestHandler.cpp:173: handle]	method:POST
[2024-12-9T13:3:41.760Z:281471788772320:streamrecorder.cpp:251: onEvent]	Handle Event for camera id = 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:41.760Z:281471788772320:VideoQueue.cpp:98: dropExtraFrames]	Q size After drop: 156 and oldest frame ts = 1733749416770
[2024-12-9T13:3:41.760Z:281471788772320:gstmux.cpp:980: onEvent]	Handling event for 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:43.48Z:281467376495584:gstmux.cpp:1290: setPlayState]	Transitioning Pipeline into PLAYING State for camera ID = 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:43.50Z:281467376495584:gstmux.cpp:1311: setPlayState]	GST_STATE_CHANGE_ASYNC (for PLAYING state) for camera ID = 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:43.65Z:281467376495584:gstmux.cpp:691: insertRowInDB]	[Success:] Insert into Database for file /root/store/video/99da38ad-5d75-4525-95d7-d202b2f96c3e/1920x1080/2024/12/09/14/1733749417930.mkv with timestamp : Mon Dec  9 13:03:37 2024

[2024-12-9T13:3:43.65Z:281467376495584:storage_management.cpp:487: addFileInProtectList]	Added file into the in protect list filePath:/root/store/video/99da38ad-5d75-4525-95d7-d202b2f96c3e/1920x1080/2024/12/09/14/1733749417930.mkv removeOrAdd:1
[2024-12-9T13:3:47.82Z:281467359587296:gstmux.cpp:947: event_probe]	Initial condition
[2024-12-9T13:3:47.82Z:281467359587296:gstmux.cpp:948: event_probe]	Resolution = 1920 x 1080
[2024-12-9T13:3:47.82Z:281467359587296:gstmux.cpp:949: event_probe]	Framerate = 25 / 1
[2024-12-9T13:3:47.82Z:281467359587296:gstmux.cpp:950: event_probe]	Stream Format = avc
[2024-12-9T13:3:47.83Z:281467384949728:gstmux.cpp:814: busWatchFunc]	GST_MESSAGE_ASYNC_DONE for camera ID = 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:47.286Z:281467636476896:fps_display.cpp:80: displayFPS]	Unique ID = recording_99da38ad-5d75-4525-95d7-d202b2f96c3e FPS = { 25.013664, 25.009625, 25.013570, 25.008801, 24.960175, 25.053459, 25.008428, 25.008862, 25.018276, 25.016599, 25.012152, 24.975457 }
[2024-12-9T13:3:49.404Z:281467376495584:gstmux.cpp:113: RecorderQos]	RecorderQos::RecorderQos
[2024-12-9T13:3:49.416Z:281467376495584:gstmux.cpp:130: RecorderQos]	Recording-qos started at:./webroot/qos/recording_qos_2024-12-09T13:03:49Z.csv
[2024-12-9T13:3:56.977Z:281467376495584:gstmux.cpp:477: muxerProcessThread]	Stopping recording on event for 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:56.977Z:281467376495584:gstmux.cpp:1411: sendEOS]	Sending EOS in MUX pipeline for camera id = 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:56.993Z:281467376495584:gstmux.cpp:191: updateDbRow]	Success: Update Database with duration 9994 and FPS = 24 for file /root/store/video/99da38ad-5d75-4525-95d7-d202b2f96c3e/1920x1080/2024/12/09/14/1733749417930.mkv with timestamp : Mon Dec  9 13:03:37 2024

[2024-12-9T13:3:56.994Z:281467376495584:storage_management.cpp:487: addFileInProtectList]	Added file into the in protect list filePath:/root/store/video/99da38ad-5d75-4525-95d7-d202b2f96c3e/1920x1080/2024/12/09/14/1733749417930.mkv removeOrAdd:0
[2024-12-9T13:3:56.997Z:281467376495584:gstmux.cpp:1379: setNULLState]	Transitioning Pipeline into NULL State for camera ID = 99da38ad-5d75-4525-95d7-d202b2f96c3e
[2024-12-9T13:3:56.999Z:281467376495584:gstmux.cpp:1395: setNULLState]	State change to NULL success for camera ID = 99da38ad-5d75-4525-95d7-d202b2f96c3e

From the camera logs that works as expected - fps detected with reasonable values:
Framerate = 30000 / 1001 or Framerate = 25 / 1, but in case of problematic camera Framerate = 0 / 0, maybe that zero frame rate is the issue.

It might be something is wrong or not aligned with encoder/decoder or rtsp pack/unpack “standards” on specific camera or in VST implementation.