regression: pulse and x11grab: audio is around 2 seconds behind video

[merulasnyde]

Summary of the bug: When recording audio+video of my screen, the captured audio is around 2 seconds behind the video. This was introduced by b2d0826513c5e76f9bad2f1f0c809bc5c8e58b0c

How to reproduce:

% ffmpeg -f pulse -ac 2 -channel_layout stereo -i default -r 60 -video_size 640x480 -f x11grab -i :0.0+0,0 -c:a libvorbis -b:a 192k -c:v libx264 -b:v 2M delayed_audio.mkv

* Start the capture (possibly with some audio already playing so pavucontrol can be checked to see whether audio is being recorded)
* Move something that can produce audio at demand into the captured region, e.g. a media player with a play/pause button.
* Periodically push the play/pause button to start and stop audio.
* Check the recorded video and see whether the audio start+stop matches the pushes of the button

ffmpeg version f77ac5131cd1c623aa54ec432cba0d922e9aa470
ffmpeg version N-106835-gf77ac5131c Copyright (c) 2000-2022 the FFmpeg developers
built with gcc 11.2.0 (Gentoo Hardened 11.2.0 p1)

configuration: --enable-libx264 --enable-libvorbis --enable-libpulse --enable-gpl --enable-ffmpeg --enable-version3 --enable-nonfree --disable-ffplay --disable-ffprobe --disable-libx265 --disable-libv4l2 --disable-libvpx --disable-nvenc --disable-nvdec --disable-cuda --disable-vaapi --disable-librtmp --disable-ffnvcodec --disable-hwaccels --disable-filters --enable-filter=scale --enable-filter=aresample --disable-decoders --disable-encoders --enable-decoder=rawvideo --enable-decoder=pcm_s16le --enable-encoder=libx264 --enable-encoder=libvorbis --disable-doc
libavutil      57. 24.101 / 57. 24.101
libavcodec     59. 27.100 / 59. 27.100
libavformat    59. 23.100 / 59. 23.100
libavdevice    59.  6.100 / 59.  6.100
libavfilter     8. 38.100 /  8. 38.100
libswscale      6.  6.100 /  6.  6.100
libswresample   4.  6.100 /  4.  6.100
libpostproc    56.  5.100 / 56.  5.100

It was fine in 4.3 and stopped working in 4.4-something.
I ran a bisect between 4.3 and some bad commit in 4.4, using the strategy outlined above to determine whether the commit is good or bad.
The bisect revealed this to be a (first) bad commit: b2d0826513c5e76f9bad2f1f0c809bc5c8e58b0c

Author: Marton Balint <cus@passwd.hu>
Date:   Sat Feb 6 19:48:51 2021 +0100

    avdevice/pulse_audio_dec: do not read undersized frames
    
    Keep on reading fragments until we got fragment_size amount of data, otherwise
    we might get frames with 1-2 samples only if pa_stream_peek is called slightly
    less frequently than sample rate.
    
    Note that fragments might contain a lot less data than fragment_size, so
    reading multiple fragments to get fragment_size amount of data is intentional.
    
    Signed-off-by: Marton Balint <cus@passwd.hu>

I was also able to reproduce it on a precompiled binary of (the same) master N-106835-gf77ac5131c-20220509 prior to the bisect.

Because it seems to be a pulse issue I imagine there is some extra info that could be useful (e.g. pertaining to my pulseaudio installation).

While I reproduced it on master, it occurred during normal use after upgrading to various versions of 4.4.

Reverting the bad commit on master seems to fix the issue.

[merulasnyde]

Also

[merulasnyde]

Clarified in the title that it is a regression and changed priority from normal to important after learning regressions should be labelled with that priority.

[Marton Balint]

I have submitted a patch series which might fix this, or at least it should restore more or less the old behaviour. Timestamp differences are probably caused by that pulseaudio might return 2 second long fragments after my change, which makes the timestamps more inaccurate. Exact pulseaudio behaviour might depend on your pulseaudio version or underlying hardware, so this fix is based on my best guess...

Can you check? Here it is:

​https://patchwork.ffmpeg.org/project/ffmpeg/list/?series=6789

[merulasnyde]

I applied the series to master 8678b75bda151ccb73d847765729d10d60ad562c

The 2 second delay/desync no longer occurs, and I can not tell a difference between the behaviour in patched head and the pre-regression behaviour.

I use the eyeballed method of starting/pausing a media player though, so I could not say if there are delays in the <100ms range.

For reference, the issue (not unexpectedly) was present in master before applying the series.

thanks

[Marton Balint]

Thanks for testing, I have pushed the fix to git master: b67ca8a7a5f443de5eacac9ed4c5d94dfe685a5b