s5p-mfc: v4l2_m2m encoding does not work

[memeka]

Summary of the bug:

v4l2_m2m encoder fails to allocate capture buffers

How to reproduce:

% ffmpeg -vcodec h264_v4l2m2m -i file -vcodec h264_v4l2m2m output
ffmpeg version: git-master
built on: 3 Oct 2017

Test device: Odroid XU4, kernel 4.9, MFC encoder/decoder codec
Example output:

[h264_v4l2m2m @ 0x7f699c10] probing device /dev/video10
[h264_v4l2m2m @ 0x7f699c10] driver 's5p-mfc' on card 's5p-mfc-dec'
[h264_v4l2m2m @ 0x7f699c10] Using device /dev/video10
[h264_v4l2m2m @ 0x7f699c10] driver 's5p-mfc' on card 's5p-mfc-dec'
[h264_v4l2m2m @ 0x7f699c10] output : H264 16 buffers initialized: 0000x0000, sizeimage 00262144, bytesperline 00262144
Stream mapping:
  Stream #0:0 -> #0:0 (h264 (h264_v4l2m2m) -> h264 (h264_v4l2m2m))
  Stream #0:1 -> #0:1 (aac (native) -> aac (native))
Press [q] to stop, [?] for help
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
detected 8 logical cores
[graph_1_in_0_1 @ 0x7f6d0720] Setting 'time_base' to value '1/48000'
[graph_1_in_0_1 @ 0x7f6d0720] Setting 'sample_rate' to value '48000'
[graph_1_in_0_1 @ 0x7f6d0720] Setting 'sample_fmt' to value 'fltp'
[graph_1_in_0_1 @ 0x7f6d0720] Setting 'channel_layout' to value '0x3f'
[graph_1_in_0_1 @ 0x7f6d0720] tb:1/48000 samplefmt:fltp samplerate:48000 chlayout:0x3f
[format_out_0_1 @ 0x7f6abc10] Setting 'sample_fmts' to value 'fltp'
[format_out_0_1 @ 0x7f6abc10] Setting 'sample_rates' to value '96000|88200|64000|48000|44100|32000|24000|22050|16000|12000|11025|8000|7350'
[AVFilterGraph @ 0x7f6ab950] query_formats: 4 queried, 9 merged, 0 already done, 0 delayed
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    Last message repeated 45 times
[h264_v4l2m2m @ 0x7f699c10] capture: NM21 12 buffers initialized: 1280x0720, sizeimage 00942144, bytesperline 00001280
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 0, sample 1, dts 0
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 1, sample 46, dts 981333
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 0, sample 1, dts 0
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 1, sample 47, dts 1002667
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 0, sample 2, dts 40000
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 1, sample 47, dts 1002667
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 0, sample 3, dts 80000
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 1, sample 47, dts 1002667
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 0, sample 4, dts 120000
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 1, sample 47, dts 1002667
cur_dts is invalid (this is harmless if it occurs once at the start per stream)
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 0, sample 5, dts 160000
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x7f680550] stream 1, sample 47, dts 1002667
[graph 0 input from stream 0:0 @ 0x7f6ebc20] Setting 'video_size' to value '1280x720'
[graph 0 input from stream 0:0 @ 0x7f6ebc20] Setting 'pix_fmt' to value '26'
[graph 0 input from stream 0:0 @ 0x7f6ebc20] Setting 'time_base' to value '1/600'
[graph 0 input from stream 0:0 @ 0x7f6ebc20] Setting 'pixel_aspect' to value '0/1'
[graph 0 input from stream 0:0 @ 0x7f6ebc20] Setting 'sws_param' to value 'flags=2'
[graph 0 input from stream 0:0 @ 0x7f6ebc20] Setting 'frame_rate' to value '25/1'
[graph 0 input from stream 0:0 @ 0x7f6ebc20] w:1280 h:720 pixfmt:nv21 tb:1/600 fr:25/1 sar:0/1 sws_param:flags=2
[AVFilterGraph @ 0x7f6d1a00] query_formats: 3 queried, 2 merged, 0 already done, 0 delayed
[h264_v4l2m2m @ 0x7f6eac70] probing device /dev/video11
[h264_v4l2m2m @ 0x7f6eac70] driver 's5p-mfc' on card 's5p-mfc-enc'
[h264_v4l2m2m @ 0x7f6eac70] Using device /dev/video11
[h264_v4l2m2m @ 0x7f6eac70] driver 's5p-mfc' on card 's5p-mfc-enc'
[h264_v4l2m2m @ 0x7f6eac70] output : NM21 16 buffers initialized: 1280x0720, sizeimage 00921856, bytesperline 00001280
[h264_v4l2m2m @ 0x7f6eac70] EXTRA_DEBUG: capture: VIDIOC_G_FMT successful, now requesting 4 buffers!
[h264_v4l2m2m @ 0x7f6eac70] EXTRA_DEBUG: capture: VIDIOC_REQBUFS failed with error 12
[h264_v4l2m2m @ 0x7f6eac70] no v4l2 capture context's buffers
[h264_v4l2m2m @ 0x7f6eac70] can't configure encoder
Error initializing output stream 0:0 -- Error while opening encoder for output stream #0:0 - maybe incorrect parameters such as bit_rate, rate, width or height
[AVIOContext @ 0x7f6e8110] Statistics: 0 seeks, 0 writeouts
[aac @ 0x7f6e7170] Qavg: 30210.250
[aac @ 0x7f6e7170] 2 frames left in the queue on closing
[AVIOContext @ 0x7f688de0] Statistics: 163840 bytes read, 0 seeks
Conversion failed!

I added a couple of extra log statements (EXTRA_DEBUG on the output above) to check why VIDIOC_REQBUFS fails, and it looks like the error is ENOMEM.

Further investigating, I found 2 suspect messages in the kernel log:

[1022534.768595] s5p-mfc 11000000.codec:: dma_alloc_coherent of size 0 failed
[1022534.774016] vidioc_reqbufs:1166: error in vb2_reqbufs() for E(D)

The second message is from the codec kernel module, which calls vb2_reqbufs() to allocate encoder memory - this call fails, and the first message is where the call fails: in the vb2_dc_alloc function from the V4L2 system (​http://elixir.free-electrons.com/linux/v4.9.52/source/drivers/media/v4l2-core/videobuf2-dma-contig.c#L156)

For context, the decoder works fine (using mpv + opengl output), both decoder and encoder work fine with gstreamer.

[memeka]

One more thing to add: encoding is working fine with the original implementation by A. Ballier, with only one small patch: ​https://github.com/mihailescu2m/FFmpeg/commit/bec067bea1a443c5f9be7b96c869f4f480483326 - but I believe the new implementation already takes care of this issue...

[Jorge Ramirez-Ortiz]

Need to investigate why the kernel driver fails to allocate the requested buffers (when that happens, encoding hasn't even started)

[Jorge Ramirez-Ortiz]

The issue is that the s5p-mfc driver does not set the encoded buffer sizes from the frame dimensions and format parameters.

I will push a work-around that sets the size field in the v4l2 structure. Newer drivers will ignore this field so there is no regression.

[jkqxz]

Fixed by 44188993a1865e6a4e204908319f06cec39d5ee9.

[Carl Eugen Hoyos]

Please don't forget to mention the ticket number in the commit message.

[Carl Eugen Hoyos]

Sorry, missed it!