This is a follow-up post from the previous post: https://devtalk.nvidia.com/default/topic/1028317/jetson-tx2/h264-encoder-latency/post/5260699/#5260699. I actually replied in that post, but for some reasons, it mentions “hidden posts not numbered”, so I need to start a new thread here.
Follow this previous question, I’ve run the camera recording sample from the tegra multimedia api for several times and keep getting different encoding profiling results (I runned the jetson_clock.sh script.):
The first one:
----------- Element = enc0 -----------
Total Profiling time = 0.865153
Average FPS = 31.2084
Total units processed = 28
Average latency(usec) = 1703
Minimum latency(usec) = 110
Maximum latency(usec) = 3464
The result seems pretty nice. Based on the profiling time, the average latency is 1.7ms. However, based on the log, it seems that the encoding latency is still larger than a frame period (33 ms). To help us understand the problem, I add another log in the encoderCapturePlaneDqCallback function, which should be called when a frame is finished encoding and waits inside a capture plane. We got the following result (I put some orange comments to help us understand):
The log is:
CONSUMER: Acquired Frame. 1828717843//1st frame acquired from the camera.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 22.//This is probably some metadata because it is only 22 bytes.
CONSUMER: Acquired Frame. 1828717844//2nd frame acquired from the camera.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 22020.//1st frame get encoded, which happens after the 2nd frame acquired from the camera.
CONSUMER: Acquired Frame. 1828717864//3rd frame acquired from the camera.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 25105.//2nd frame get encoded.
CONSUMER: Acquired Frame. 1828717866//4th frame acquired from the camera.
…
CONSUMER: Acquired Frame. 1828717844//nst frame acquired from the camera.
CONSUMER: Released frame. 1828717864
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 19179.//(n-1)th frame get encoded.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 19732.//nth frame get encoded.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 0.
CONSUMER: Got EOS, exiting…
CONSUMER: Done.
We find that the encoding latency from the time frame acquired from the camera to the time the frame finishes encoding is longer than a frame time (33ms).
The second result:
----------- Element = enc0 -----------
Total Profiling time = 0.861473
Average FPS = 31.3417
Total units processed = 28
Average latency(usec) = 32612
Minimum latency(usec) = 260
Maximum latency(usec) = 35255
The average encoding latency is 32.6ms, which is around a frame period, but the log shows the latency is actually larger than 2 frame periods (66.7ms).
CONSUMER: Acquired Frame. 1828717843//1st frame.
CONSUMER: Acquired Frame. 1828717844//2nd frame.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 22.//This is probably some metadata because it is only 22 bytes.
CONSUMER: Acquired Frame. 1828717864//3rd frame.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 22020.//1st frame get encoded.
CONSUMER: Acquired Frame. 1828717866//4th frame.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 25008.//2nd frame get encoded.
…
CONSUMER: Acquired Frame. 1828717844//nst frame acquired from the camera.
CONSUMER: Released frame. 1828717864
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 24758.//(n-2)th frame get encoded.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 25853.//(n-1)th frame get encoded.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 18977.//nth frame get encoded.
CONSUMER: encoderCapturePlaneDqCallback, encoded frame size: 0.
CONSUMER: Got EOS, exiting…
CONSUMER: Done.
PRODUCER: Done – exiting.
[b]From this result, we verify the argument that each frame will finish encoding after 1 or 2 frame periods + some time. Since I’m capturing 30fps video with 640x480 resolution, the time of 2 frame periods is 66.7ms.
So the results are really wired, here are three main questions:
- Why does the encoding profiling result keep changing?
- Why does the log show longer encoding latency than the profiling result?
- Can we really force every frame to be decoded straight away without waiting for the next frame?
Current high-end smartphones can encode a 640*480 frame within 10ms, it will be embarrassing if Jetson requires more than 66ms to do so…[/b]