`h264decrypt` (during receiving `rtp` over `udp`) fails after few seconds

[inobelar]

Greetings! This issue is similar to https://github.com/ReFormationPro/Gstreamer-H264-Encryption/issues/4 , but now I'm tried to send h264-encoded video, wrapped intortp protocol via udp (on localhost).

I launch 'Receiver' first, and 'Sender' after it. 'Receiver' show few first frames (so it decrypt them correctly) then glitches, than completely fails.

• x264enc & rtph264pay properties values dont affect behavior - even with default properties, 'Receiver' fails for a few seconds.

• For simplicity i dont use rtp-related 'tuning':

  • On 'Sender' side: rtph264pay::aggregate-mode
  • On 'Receiver' side: rtpjittebuffer (before rtph264depay)

• Sender pipeline:

  $ GST_PLUGIN_PATH=/home/vuser/work/Gstreamer-H264-Encryption/build \
  GST_DEBUG=3 \
  gst-launch-1.0 --verbose \
      videotestsrc do-timestamp=true pattern=ball ! \
          "video/x-raw, width=640, height=480, framerate=30/1" ! \
      timeoverlay ! \
      x264enc \
          tune=zerolatency \
          speed-preset=ultrafast \
          bitrate=1000 \
          threads=1 ! \
      h264encrypt \
          iv-seed=1869052520 \
          key=01234567012345670123456701234567 \
          encryption-mode=aes-cbc ! \
      rtph264pay config-interval=1 ! \
      udpsink \
          host=127.0.0.1 \
          port=5000

  STDOUT LOG

  ``` Setting pipeline to PAUSED ... Pipeline is PREROLLING ... 0:00:00.113100598 2957 0x7fc100000b70 FIXME default gstutils.c:4088:gst_element_decorate_stream_id_internal: Creating random stream-id, consider implementing a deterministic way of creating a stream-id /GstPipeline:pipeline0/GstVideoTestSrc:videotestsrc0.GstPad:src: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, framerate=(fraction)30/1, multiview-mode=(string)mono, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive /GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, framerate=(fraction)30/1, multiview-mode=(string)mono, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive /GstPipeline:pipeline0/GstTimeOverlay:timeoverlay0.GstPad:src: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, framerate=(fraction)30/1, multiview-mode=(string)mono, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive Redistribute latency... /GstPipeline:pipeline0/GstX264Enc:x264enc0.GstPad:sink: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, framerate=(fraction)30/1, multiview-mode=(string)mono, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive /GstPipeline:pipeline0/GstTimeOverlay:timeoverlay0.GstPad:video_sink: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, framerate=(fraction)30/1, multiview-mode=(string)mono, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive /GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:sink: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, framerate=(fraction)30/1, multiview-mode=(string)mono, pixel-aspect-ratio=(fraction)1/1, interlace-mode=(string)progressive /GstPipeline:pipeline0/GstX264Enc:x264enc0.GstPad:src: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3, profile=(string)high-4:4:4, width=(int)640, height=(int)480, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt601, chroma-site=(string)jpeg, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono /GstPipeline:pipeline0/GstH264Encrypt:h264encrypt0.GstPad:src: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3, profile=(string)high-4:4:4, width=(int)640, height=(int)480, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt601, chroma-site=(string)jpeg, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono /GstPipeline:pipeline0/GstRtpH264Pay:rtph264pay0.GstPad:sink: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3, profile=(string)high-4:4:4, width=(int)640, height=(int)480, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt601, chroma-site=(string)jpeg, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono /GstPipeline:pipeline0/GstH264Encrypt:h264encrypt0.GstPad:sink: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au, level=(string)3, profile=(string)high-4:4:4, width=(int)640, height=(int)480, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30/1, interlace-mode=(string)progressive, colorimetry=(string)bt601, chroma-site=(string)jpeg, multiview-mode=(string)mono, multiview-flags=(GstVideoMultiviewFlagsSet)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono /GstPipeline:pipeline0/GstRtpH264Pay:rtph264pay0: extensions = < > /GstPipeline:pipeline0/GstRtpH264Pay:rtph264pay0.GstPad:src: caps = application/x-rtp, media=(string)video, payload=(int)96, clock-rate=(int)90000, encoding-name=(string)H264, ssrc=(uint)3106688681, timestamp-offset=(uint)4004126462, seqnum-offset=(uint)22307, a-framerate=(string)30 /GstPipeline:pipeline0/GstUDPSink:udpsink0.GstPad:sink: caps = application/x-rtp, media=(string)video, payload=(int)96, clock-rate=(int)90000, encoding-name=(string)H264, ssrc=(uint)3106688681, timestamp-offset=(uint)4004126462, seqnum-offset=(uint)22307, a-framerate=(string)30 /GstPipeline:pipeline0/GstRtpH264Pay:rtph264pay0: extensions = < > /GstPipeline:pipeline0/GstRtpH264Pay:rtph264pay0.GstPad:src: caps = application/x-rtp, media=(string)video, clock-rate=(int)90000, encoding-name=(string)H264, packetization-mode=(string)1, sprop-parameter-sets=(string)"Z/QAHpDZaAoD2wFqDAwMgAAAAwCAAAAeR4sXUA\=\=\,aM4xkg\=\=", payload=(int)96, seqnum-offset=(uint)22307, timestamp-offset=(uint)4004126462, ssrc=(uint)3106688681, a-framerate=(string)30 /GstPipeline:pipeline0/GstUDPSink:udpsink0.GstPad:sink: caps = application/x-rtp, media=(string)video, clock-rate=(int)90000, encoding-name=(string)H264, packetization-mode=(string)1, sprop-parameter-sets=(string)"Z/QAHpDZaAoD2wFqDAwMgAAAAwCAAAAeR4sXUA\=\=\,aM4xkg\=\=", payload=(int)96, seqnum-offset=(uint)22307, timestamp-offset=(uint)4004126462, ssrc=(uint)3106688681, a-framerate=(string)30 /GstPipeline:pipeline0/GstRtpH264Pay:rtph264pay0: timestamp = 4004126462 /GstPipeline:pipeline0/GstRtpH264Pay:rtph264pay0: seqnum = 22307 Pipeline is PREROLLED ... Setting pipeline to PLAYING ... Redistribute latency... New clock: GstSystemClock ^Chandling interrupt. Interrupt: Stopping pipeline ... Execution ended after 0:00:07.071810603 Setting pipeline to NULL ... Freeing pipeline ... ```

• Receiver pipeline:

  $ GST_PLUGIN_PATH=/home/vuser/work/Gstreamer-H264-Encryption/build \
  GST_DEBUG=3 \
  DISPLAY=:0.0 \
  gst-launch-1.0 --verbose \
      udpsrc \
          port=5000 ! \
          "application/x-rtp, media=(string)video, clock-rate=(int)90000, encoding-name=(string)H264, payload=(int)96" ! \
      rtph264depay ! \
      h264decrypt \
          key=01234567012345670123456701234567 \
          encryption-mode=aes-cbc ! \
      avdec_h264 ! \
      videoconvert ! \
      ximagesink \
          sync=false

  STDOUT LOG

  ``` Setting pipeline to PAUSED ... Pipeline is live and does not need PREROLL ... Pipeline is PREROLLED ... Setting pipeline to PLAYING ... New clock: GstSystemClock /GstPipeline:pipeline0/GstCapsFilter:capsfilter0.GstPad:src: caps = application/x-rtp, media=(string)video, clock-rate=(int)90000, encoding-name=(string)H264, payload=(int)96 /GstPipeline:pipeline0/GstRtpH264Depay:rtph264depay0: extensions = < > /GstPipeline:pipeline0/GstRtpH264Depay:rtph264depay0.GstPad:src: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au /GstPipeline:pipeline0/GstH264Decrypt:h264decrypt0.GstPad:src: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au Redistribute latency... /GstPipeline:pipeline0/avdec_h264:avdec_h264-0.GstPad:sink: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au /GstPipeline:pipeline0/GstH264Decrypt:h264decrypt0.GstPad:sink: caps = video/x-h264, stream-format=(string)byte-stream, alignment=(string)au /GstPipeline:pipeline0/GstRtpH264Depay:rtph264depay0.GstPad:sink: caps = application/x-rtp, media=(string)video, clock-rate=(int)90000, encoding-name=(string)H264, payload=(int)96 /GstPipeline:pipeline0/avdec_h264:avdec_h264-0.GstPad:src: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)mpeg2, colorimetry=(string)bt601, framerate=(fraction)25/2 /GstPipeline:pipeline0/GstVideoConvert:videoconvert0.GstPad:src: caps = video/x-raw, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)25/2, format=(string)BGRx, colorimetry=(string)1:1:16:4 /GstPipeline:pipeline0/GstXImageSink:ximagesink0.GstPad:sink: caps = video/x-raw, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)25/2, format=(string)BGRx, colorimetry=(string)1:1:16:4 /GstPipeline:pipeline0/GstVideoConvert:videoconvert0.GstPad:sink: caps = video/x-raw, format=(string)Y444_10LE, width=(int)640, height=(int)480, interlace-mode=(string)progressive, pixel-aspect-ratio=(fraction)1/1, chroma-site=(string)mpeg2, colorimetry=(string)bt601, framerate=(fraction)25/2 Redistribute latency... 0:00:03.738405739 2951 0x708c34000b70 ERROR h264decrypt h264_decrypt.c:276:gst_h264_decrypt_decrypt_slice_nalu: Encrypted block size (3039) is not a multiple of AES_BLOCKLEN (16). Not attempting to decrypt. 0:00:03.738815249 2951 0x708c34000b70 ERROR h264decrypt h264_decrypt.c:200:gst_h264_decrypt_process_slice_nalu: Failed to decrypt slice nal unit 0:00:03.739230014 2951 0x708c34000b70 ERROR h264encryptionbase h264_encryption_base.c:309:gst_h264_encryption_base_transform: Subclass failed to parse slice nalu 0:00:03.756037217 2951 0x708c34000b70 WARN basesrc gstbasesrc.c:3177:gst_base_src_loop: error: Internal data stream error. 0:00:03.756490731 2951 0x708c34000b70 WARN basesrc gstbasesrc.c:3177:gst_base_src_loop: error: streaming stopped, reason error (-5) ERROR: from element /GstPipeline:pipeline0/GstUDPSrc:udpsrc0: Internal data stream error. Additional debug info: ../libs/gst/base/gstbasesrc.c(3177): gst_base_src_loop (): /GstPipeline:pipeline0/GstUDPSrc:udpsrc0: streaming stopped, reason error (-5) Execution ended after 0:00:03.223455644 Setting pipeline to NULL ... Freeing pipeline ... ```

[inobelar]

Update: Even without udp usage h264decrypt fails in the next case (rtp payload and immediate depayload):

$ GST_PLUGIN_PATH=/home/vuser/work/Gstreamer-H264-Encryption/build \
  GST_DEBUG=5 \
  DISPLAY=:0.0 \
  gst-launch-1.0 --verbose \
    videotestsrc do-timestamp=true pattern=ball ! \
        "video/x-raw, width=640, height=480, framerate=30/1" ! \
    timeoverlay ! \
    x264enc ! \
    \
    h264encrypt \
        iv-seed=1869052520 \
        key=01234567012345670123456701234567 \
        encryption-mode=aes-cbc ! \
    \
    rtph264pay config-interval=1 ! \
    rtph264depay ! \
    \
    h264decrypt \
        key=01234567012345670123456701234567 \
        encryption-mode=aes-cbc ! \
    \
    avdec_h264 ! \
    videoconvert ! \
    ximagesink \
        sync=true

End of huge STDOUT log (GST_DEBUG=5)

``` 0:00:10.290624942 4462 0x717508000b70 DEBUG h264encryptionbase h264_encryption_base.c:235:gst_h264_encryption_base_transform: A buffer is received 0:00:10.290646279 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:250:gst_h264_parse_nalu_header: Nal type 9, ref_idc 0 0:00:10.290784355 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:1577:gst_h264_parser_identify_nalu: Complete nal found. Off: 4, Size: 2 0:00:10.290802990 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:250:gst_h264_parse_nalu_header: Nal type 6, ref_idc 0 0:00:10.290818619 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:1577:gst_h264_parser_identify_nalu: Complete nal found. Off: 10, Size: 36 0:00:10.290908812 4462 0x717508000b70 DEBUG h264decrypt h264_decrypt.c:150:gst_h264_decrypt_before_nalu_copy: found SEI 0:00:10.290926120 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:2731:gst_h264_parser_parse_sei: parsing SEI nal 0:00:10.290941057 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:1317:gst_h264_parser_parse_sei_message: parsing "SEI message" 0:00:10.290992918 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:1337:gst_h264_parser_parse_sei_message: SEI message received: payloadType 5, payloadSize = 256 bits 0:00:10.291044951 4462 0x717508000b70 DEBUG h264decrypt h264_decrypt.c:160:gst_h264_decrypt_before_nalu_copy: found the User Data Unregistered SEI 0:00:10.291060145 4462 0x717508000b70 DEBUG h264decrypt h264_decrypt.c:177:gst_h264_decrypt_before_nalu_copy: IV is found 0:00:10.291076283 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:250:gst_h264_parse_nalu_header: Nal type 1, ref_idc 2 0:00:10.291164505 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:1562:gst_h264_parser_identify_nalu: Nal start 50, No end found 0:00:10.291181687 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:250:gst_h264_parse_nalu_header: Nal type 1, ref_idc 2 0:00:10.291196691 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:1562:gst_h264_parser_identify_nalu: Nal start 10, No end found 0:00:10.291388981 4462 0x717508000b70 DEBUG h264encryptionbase h264_encryption_base.c:287:gst_h264_encryption_base_transform: Source nal unit is copied. Type 1 sc_offset 46 total_size 488 0:00:10.291407508 4462 0x717508000b70 DEBUG h264encryptionbase h264_encryption_base.c:293:gst_h264_encryption_base_transform: Copied nal unit is parsed. Type 1 sc_offset 6 total_size 488 expected size 488 0:00:10.291424456 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:2467:gst_h264_parser_parse_slice_hdr: parsing "Slice header", slice type 5 0:00:10.291440802 4462 0x717508000b70 DEBUG codecparsers_h264 gsth264parser.c:709:gst_h264_slice_parse_dec_ref_pic_marking: parsing "Decoded reference picture marking" 0:00:10.291458311 4462 0x717508000b70 ERROR h264decrypt h264_decrypt.c:276:gst_h264_decrypt_decrypt_slice_nalu: Encrypted block size (479) is not a multiple of AES_BLOCKLEN (16). Not attempting to decrypt. 0:00:10.291476784 4462 0x717508000b70 ERROR h264decrypt h264_decrypt.c:200:gst_h264_decrypt_process_slice_nalu: Failed to decrypt slice nal unit 0:00:10.291491048 4462 0x717508000b70 ERROR h264encryptionbase h264_encryption_base.c:309:gst_h264_encryption_base_transform: Subclass failed to parse slice nalu ```

[oguzhanoztaskin]

Yes, this seems to be related. Off-by-one error again. I will compare payloads to see where in the payload the error occurs.

[oguzhanoztaskin]

This is also fixed because of the fix for #4 so I am closing it.