SM
Software Mansion•10mo ago
spscream

h264 encoder problems

hi guys, I'm using h264 encoder plugin for video encoding and sending it via rtp to client. Sometimes video play on client speeds up or speeds down. How to debug such cases and what could be a reason of such lagging video? Network issues? input for encoder is coming from webrtc source
4 Replies
spscream
spscreamOP•10mo ago
I tried to put RealTimer before SessioBin, but it doesn't help 
    spec = {[
      get_child(:video_vr_subscriber)
      |> via_out(Pad.ref(:output, ssrc))
      |> child(:vr_subscriber_tee, Tee.Parallel)
      |> child(:h264_encoder, %Membrane.H264.FFmpeg.Encoder{
        profile: :main
      })
      |> child(:h264_parser, %Membrane.H264.Parser{
        output_alignment: :nalu
      })
      |> via_in(Pad.ref(:input, state.video_ssrc), options: [
        payloader: %RTP.H264.Payloader{max_payload_size: 1200}
      ])
      |> get_child(:sip_rtp)
      |> via_out(Pad.ref(:rtp_output, state.video_ssrc), options: [encoding: :H264, payload_type: 99])
      |> child(:realtimer, Membrane.Realtimer)
      |> via_in(Pad.ref(:input))
      |> get_child(:sip_video),
      get_child(:vr_subscriber_tee)
      |> child(:my_sink, MySink),
    ], stream_sync: :sinks}
    spec = {[
      get_child(:video_vr_subscriber)
      |> via_out(Pad.ref(:output, ssrc))
      |> child(:vr_subscriber_tee, Tee.Parallel)
      |> child(:h264_encoder, %Membrane.H264.FFmpeg.Encoder{
        profile: :main
      })
      |> child(:h264_parser, %Membrane.H264.Parser{
        output_alignment: :nalu
      })
      |> via_in(Pad.ref(:input, state.video_ssrc), options: [
        payloader: %RTP.H264.Payloader{max_payload_size: 1200}
      ])
      |> get_child(:sip_rtp)
      |> via_out(Pad.ref(:rtp_output, state.video_ssrc), options: [encoding: :H264, payload_type: 99])
      |> child(:realtimer, Membrane.Realtimer)
      |> via_in(Pad.ref(:input))
      |> get_child(:sip_video),
      get_child(:vr_subscriber_tee)
      |> child(:my_sink, MySink),
    ], stream_sync: :sinks}
I have the following pipeline part for it full logic of my pipeline is the following: webrtc subscription for video from janus gateway -> vp8 decode -> h264 encode -> rtp output to sip client I implemented vp8 encoder/decoder plugin (https://github.com/spscream/membrane_vp8_ffmpeg_plugin it is in WIP state now) for membrane to decode vp8, using membrane_h264_ffmpeg_plugin as an example, it makes decoding and encoding of vp8 for my case. Is it reason could be in non-monotonically growing pts in incoming buffers? I have subscriber connection to janus, which is calling "switch" to janus on on "talking" events from janus, to switch video to new speaker if it is talking right now. I added sink to debug buffers and it is showing, what pts isn't monotonically increased, in log diff is the prev buffer pts - current pts 
22:28:10.208 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97870544444 dts: , diff: 32000000 len: 3686400
22:28:10.257 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97902544444 dts: , diff: 32000000 len: 3686400
22:28:10.287 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97950544444 dts: , diff: 48000000 len: 3686400
22:28:10.304 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97982544444 dts: , diff: 32000000 len: 3686400
22:28:10.351 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97998544444 dts: , diff: 16000000 len: 3686400
22:28:10.375 pid=<0.1397.0> [warning] calling to switch subscriber stream
22:28:10.375 pid=<0.1397.0> [info] [%{"feed" => 1515747746186501, "mid" => "1"}]
22:28:10.375 pid=<0.1397.0> [info] [%{"feed" => 1515747746186501, "mid" => "1", "sub_mid" => "0"}]
22:28:10.376 pid=<0.1397.0> [info] JanusSubscriberSession janus_ws: %{"janus" => "ack", "session_id" => 416529640432331, "transaction" => "bgs1t3lt2No"}
22:28:10.376 pid=<0.1397.0> [info] JanusSubscriberSession janus_ws: %{"janus" => "event", "plugindata" => ...}
22:28:10.382 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98046544444 dts: , diff: 48000000 len: 3686400
22:28:10.397 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98075566666 dts: , diff: 29022222 len: 3686400
22:28:10.411 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98091566666 dts: , diff: 16000000 len: 3686400
22:28:10.636 pid=<0.1985.0> [info] <0.1281.0>/:video_vr_subscriber/:vp8_decoder generate_stream_format_change: 320 180
22:28:10.637 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98106566666 dts: , diff: 15000000 len: 3686400
22:28:10.637 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98123566666 dts: , diff: 17000000 len: 3686400
22:28:10.208 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97870544444 dts: , diff: 32000000 len: 3686400
22:28:10.257 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97902544444 dts: , diff: 32000000 len: 3686400
22:28:10.287 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97950544444 dts: , diff: 48000000 len: 3686400
22:28:10.304 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97982544444 dts: , diff: 32000000 len: 3686400
22:28:10.351 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 97998544444 dts: , diff: 16000000 len: 3686400
22:28:10.375 pid=<0.1397.0> [warning] calling to switch subscriber stream
22:28:10.375 pid=<0.1397.0> [info] [%{"feed" => 1515747746186501, "mid" => "1"}]
22:28:10.375 pid=<0.1397.0> [info] [%{"feed" => 1515747746186501, "mid" => "1", "sub_mid" => "0"}]
22:28:10.376 pid=<0.1397.0> [info] JanusSubscriberSession janus_ws: %{"janus" => "ack", "session_id" => 416529640432331, "transaction" => "bgs1t3lt2No"}
22:28:10.376 pid=<0.1397.0> [info] JanusSubscriberSession janus_ws: %{"janus" => "event", "plugindata" => ...}
22:28:10.382 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98046544444 dts: , diff: 48000000 len: 3686400
22:28:10.397 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98075566666 dts: , diff: 29022222 len: 3686400
22:28:10.411 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98091566666 dts: , diff: 16000000 len: 3686400
22:28:10.636 pid=<0.1985.0> [info] <0.1281.0>/:video_vr_subscriber/:vp8_decoder generate_stream_format_change: 320 180
22:28:10.637 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98106566666 dts: , diff: 15000000 len: 3686400
22:28:10.637 pid=<0.1953.0> [info] <0.1281.0>/:my_sink handle_buffer: pts: 98123566666 dts: , diff: 17000000 len: 3686400
also I see what for first video stream is coming with full vp8 frame per packet, after switch is coming splitted, timestamps on incoming rtp from subscriber stream: 
00:18:21.171 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2974099 diff: 1350
00:18:21.192 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2975449 diff: 1350
00:18:21.215 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2976889 diff: 1440
00:18:21.227 pid=<0.1401.0> [warning] calling to switch subscriber stream
...
00:18:21.228 pid=<0.1401.0> [info] JanusSubscriberSession janus_ws: %{"janus" => "event", "plugindata" => ...
00:18:21.239 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 2168
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.283 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2981937 diff: 2880
00:18:21.171 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2974099 diff: 1350
00:18:21.192 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2975449 diff: 1350
00:18:21.215 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2976889 diff: 1440
00:18:21.227 pid=<0.1401.0> [warning] calling to switch subscriber stream
...
00:18:21.228 pid=<0.1401.0> [info] JanusSubscriberSession janus_ws: %{"janus" => "event", "plugindata" => ...
00:18:21.239 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 2168
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.240 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2979057 diff: 0
00:18:21.283 pid=<0.2013.0> [info] <0.1285.0>/:video_vr_subscriber/:rtp/{:stream_receive_bin, 2635607903}/:depayloader/:depayloader timestamp: 2981937 diff: 2880
may be different frame rates in incoming videos could be the reason... I set zerolatency tune for h264 encoder and framerate to {0,1} for vp8 decoder and now it looks good problem is solved, thanks 😄
Qizot
Qizot•10mo ago
zerolatency mode basically removes B-frames which should not be used for rtp/webrtc stuff (b-frames can have pts going back in time)
mat_hek
mat_hek•10mo ago
Hi @spscream , some insights that may be helpful - If PTS are not monotonic, that means they're either broken or you have B-frames in the stream. As @Qizot said, they shouldn't be used for real-time streaming as they introduce latency, and due to that they're sometimes not properly handled by endpoints. Normally, you set the H264 encoder profile to baseline or constrained baseline for live streaming. These profiles don't include B-frames. - Don't rely on framerate, as it may change at any moment. Rely on timestamps - Generally, media servers usually don't apply pacing (like realtimer), they just forward media and the pacing is the job of the player - Congrats for creating the VP8 plugin, though it seems it's not public as your link doesn't work 😉
spscream
spscreamOP•10mo ago
thank you for insights, I moved repo in public I also should mention, what i'm using swscale directly on decoder output in c code. I have a special case with switch stream on janus subscription - frame size could be different for published videos, so I had to add it in decoder. I tried to use swscale plugin in pipeline with no success and faster for my case was to implement it in decoder. In future I'll move this logic to separate membrane element, but I have deadlines now and it works for me now - decoder gives me constant frame format for outputs.
Want results from more Discord servers?
Add your server