Measuring Latency
Libxcoder can be compiled to generate latency information for both the decoder and encoder. The information can be output to the FFmpeg log. This can then be used to plot latency as shown in the graph above.
Note the following section describes the encoder latency measurement only, the decoder latency measurement can be created using a similar method.
The libXcoder Latency reporting mechanism reports per frame latency for the frame’s duration through the Quadra hardware. It prints logs to stderr.
Compiling the Latency Reporting Mechanism
To enable latency reporting, compile the libXcoder with the ‘--with-latency-display’ flag, or its short form, ‘-p’:
cd libxcoder
./build.sh -p
Next compile FFmpeg, libAVcodec, or any custom application that is integrated with Quadra.
See the “Build FFmpeg with NETINT Codec Library” section in the QuickStartGuideQuadra_*.pdf for more instructions on the installation of the FFmpeg application.
Running FFmpeg with low-delay mode encoder
To provide the best throughput of frames, libXcoder’s default operation mode allows frames to be buffered in the decoder/encoder input queue on the Quadra device itself. If the lowest latency is desired the lowDelay xcoder parameter can be used. This will cause libXcoder to attempt to retrieve a processed frame before sending the next frame.
An example FFmpeg command with the lowDelay xcoder-param:
ffmpeg -y -nostdin -hide_banner -vsync 0 -stream_loop 1 -f rawvideo -pix_fmt yuv420p -s:v 1920x1080 -r 25 -i /mnt/ramdisk/dinner_1920x1080p30_300_br7500_b3__B265d.yuv -c:v h265_ni_quadra_enc -enc 0 -xcoder-params gopPresetIdx=3:lowDelay=1:RcEnable=1:bitrate=4000000 -f null - 2>&1
Latency Logs
When decoding or transcoding through Quadra, latency report messages will appear in the stderr of the terminal thus:
1642192725.181572 DTS:323,DELTA:8008256,eLAT:6166089;
1642192725.181599 DTS:324,DELTA:7805161,eLAT:5912997;
1642192725.181626 DTS:325,DELTA:7884774,eLAT:6053380;
1642192725.181652 DTS:326,DELTA:7990645,eLAT:6149894;
1642192725.181679 DTS:327,DELTA:7730706,eLAT:5903105;
1642192725.181705 DTS:328,DELTA:7895577,eLAT:6055641;
1642192725.181732 DTS:329,DELTA:7685357,eLAT:5832137;
1642192725.181758 DTS:330,DELTA:7506154,eLAT:5675062;
1642192725.181786 DTS:331,DELTA:7538778,eLAT:5747147;
1642192725.181812 DTS:332,DELTA:7834258,eLAT:6022893;
They describe:
| DTS | Decoding time stamp of frame in the timebase transmitted to libXcoder |
| DELTA | Frame period between this frame and previous frame in nanoseconds |
| dLAT | HW decoder latency for frame of this DTS in nanoseconds |
| eLAT | HW encoder latency for frame of this DTS in nanoseconds |
Interpreting Latency Results
The measurement mechanism exists at the lowest level of libXcoder, immediately before any frames/packets are sent to, or received from, Quadra Hardware. The latency measured does not account for any time spent within the FFmpeg, libAVcodec, or other parts of the libXcoder call stack. Though this time is typically very low for functions using the APIs.
As the measurement mechanism is in libXcoder it is also dependent on higher level APIs calling the function to retrieve frame from the decoder/encoder output buffer. The processing rate control mechanisms such as FFmpeg’s “-re” can cause the minimum measured latency to be higher than the frame period.
Also, be aware that the hardware sided buffering mechanisms can also cause latency. If a plot of the measured latency appears to show any linear increase in latency from the beginning of a stream, then the decoder/encoder buffer is likely working. These buffers allow frames to be sent to the hardware before they are processed and sent back to the libXcoder. The “lowDelay” encoder parameter can be used to restrict this buffering behavior on the encoder. The “-re” ffmpeg mechanism to limit the processing frame rate can be used to regulate the frame send-rate to the decoder, in order to minimize hardware buffering.
Encoder Latency Measurement
Scope
This section will demonstrate the collection of latency measurement data for Quadra.
The Quadra and FFmpeg environment configuration and usage is not in the scope of this section. The document assumes a Linux host installed with a Quadra card and with libxcoder and FFmpeg successfully compiling and Quadra demonstrated for video transcoding operation.
Using libxcoder latency logs
This method includes enabling print outs for encoder latency time and then parsing the log data
to determine the latency measurement.
Build libxcoder with -p flag
Run the libxcoder build with the -p flag for latency patch.
sh build.sh -p
sudo make install
Build FFmpeg as usual.
Collect eLAT data
Run the following ffmpeg encode command with a yuv file input. It will generate an output log file
ffmpeg -y -nostdin -hide_banner -vsync 0 -stream_loop 1 -f rawvideo -pix_fmt yuv420p -s:v 1920x1080 -r 25 -i /mnt/ramdisk/dinner_1920x1080p30_300_br7500_b3__B265d.yuv -c:v h265_ni_quadra_enc -enc 0 -xcoder-params gopPresetIdx=3:lowDelay=1:RcEnable=1:bitrate=4000000 -f null - 2>&1 |ts '%.s' > output-y2h-0-0-0.log
The output log file will have extra log messages as follows.
1642193165.553249 DTS:1,DELTA:6965127,eLAT:5511326;
1642193165.553276 DTS:2,DELTA:8132467,eLAT:5629519;
1642193165.553303 DTS:3,DELTA:9577126,eLAT:5670137;
1642193165.553330 DTS:4,DELTA:9994202,eLAT:5658198;
1642193165.553357 DTS:5,DELTA:7654552,eLAT:5642386;
1642193165.553384 DTS:6,DELTA:10671531,eLAT:5939394;
1642193165.553411 DTS:7,DELTA:10420093,eLAT:6033683;
where,
| DTS | Decoding time stamp of frame in the timebase transmitted to libXcoder |
| DELTA | Frame period between this frame and previous frame in nanoseconds |
| eLAT | HW encoder latency for frame of this DTS in nanoseconds |
Measure Latency
Parse the output log file to collect the eLAT time stamps.
cat output-y2h-0-0-0.log | sed 's/;/ /g' | grep "eLAT:" | cut -d"," -f3 | sed 's/eLAT:/ /g'> encoder-out_time-y2h-0-0-0.log
Collate the parsed eLAT data to a csv file.
The parsed data will be as sample below:
5511326
5629519
5670137
5658198
5642386
5939394
6033683
Calculate the eLAT / 1000000 to get the latency msec.
Using ffmpeg -debug_ts
This method can be used for collecting latency measurements for T408 and any 3rd party GPU like Nvidia or AMD.
Please note that the method measures latency approximately and it is suggested not to use it on Quadra because a more accurate method was provided in the previous sections.
- Run ffmpeg command to perform encoding operation. Use -c:v parameter to specify video encoder to use like h264_ni_quadra_enc or h265_ni_quadra_enc for NETINT encoder.
T408 example:
ffmpeg -y -nostdin -hide_banner -vsync 0 -debug_ts -stream_loop 1 -f rawvideo -pix_fmt yuv420p -s:v 1920x1080 -r 25 -i /mnt/ramdisk/dinner_1920x1080p30_300_br7500_b3__B265d.yuv -c:v h265_ni_quadra_enc -enc 0 -xcoder-params gopPresetIdx=3:lowDelay=1:RcEnable=1:bitrate=4000000 -f null - 2>&1 |ts '%.s' > output-y2h-0-0-0.log
The output log file, for T408 as example, will have extra log messages as follows.
1642199011.985473 muxer <- type:video pkt_pts:1 pkt_pts_time:0.04 pkt_dts:-6 pkt_dts_time:-0.24 size:964
1642199011.987290 demuxer -> ist_index:0 type:video next_dts:80000 next_dts_time:0.08 next_pts:80000 next_pts_time:0.08 pkt_pts:2 pkt_pts_time:0.08 pkt_dts:2 pkt_dts_time:0.08 off:0 off_time:0
1642199011.987346 demuxer+ffmpeg -> ist_index:0 type:video pkt_pts:2 pkt_pts_time:0.08 pkt_dts:2 pkt_dts_time:0.08 off:0 off_time:0
1642199011.987362 decoder -> ist_index:0 type:video frame_pts:2 frame_pts_time:0.08 best_effort_ts:2 best_effort_ts_time:0.08 keyframe:1 frame_type:1 time_base:1/25
1642199011.987376 filter -> pts:2 pts_time:0.08 exact:2.000008 time_base:1/25
1642199011.987390 encoder <- type:video frame_pts:2 frame_pts_time:0.08 time_base:1/25
1642199011.993528 encoder -> type:video pkt_pts:2 pkt_pts_time:0.08 pkt_dts:-5 pkt_dts_time:-0.2
1642199011.993600 Last message repeated 1 times
- Filter and record latency data from output log
cat output-y2h-0-0-0.log | grep "encoder <-" | cut -d" " -f1 > encoder-in_time-0-0.log && cat output-$tag.log | grep "encoder ->" | cut -d" " -f1 > encoder-out_time-0-0-0.log
- Collate the encoder in time and encoder out time stamps to a csv file.
Sample encoder in times:
1642199011.987390
1642199011.997031
1642199012.007143
1642199012.015154
1642199012.025613
1642199012.035669
1642199012.043303
1642199012.053758
Sample encoder out times:
1642199011.993528
1642199012.003550
1642199012.013914
1642199012.021652
1642199012.032136
1642199012.042110
1642199012.049788
1642199012.060334
- Calculate the output log encoder out and encoder in time stamps diff * 1000 to get the latency msec.