stream.ffmpegmux: validate FFmpeg version

and log FFmpeg version output on the debug logging level

src/streamlink/session.py

@@ -81,6 +81,7 @@ class Streamlink:
             "stream-segment-timeout": 10.0,
             "stream-timeout": 60.0,
             "ffmpeg-ffmpeg": None,
+            "ffmpeg-no-validation": False,
             "ffmpeg-fout": None,
             "ffmpeg-video-transcode": None,
             "ffmpeg-audio-transcode": None,
@@ -168,6 +169,9 @@ class Streamlink:
                                  ffmpeg executable use by Muxing streams
                                  e.g. ``/usr/local/bin/ffmpeg``
 
+        ffmpeg-no-validation     (bool) Disable FFmpeg validation and version logging.
+                                 default: ``False``
+
         ffmpeg-verbose           (bool) Log stderr from ffmpeg to the
                                  console
 

src/streamlink/stream/ffmpegmux.py

@@ -1,20 +1,25 @@
 import concurrent.futures
 import logging
+import re
 import subprocess
 import sys
 import threading
 from functools import lru_cache
 from pathlib import Path
 from shutil import which
-from typing import Optional
+from typing import List, Optional
 
 from streamlink import StreamError
 from streamlink.compat import devnull
 from streamlink.stream.stream import Stream, StreamIO
 from streamlink.utils.named_pipe import NamedPipe, NamedPipeBase
+from streamlink.utils.processoutput import ProcessOutput
+
 
 log = logging.getLogger(__name__)
 
+_lock_resolve_command = threading.Lock()
+
 
 class MuxedStream(Stream):
     """
@@ -78,17 +83,24 @@ class FFMPEGMuxer(StreamIO):
     DEFAULT_VIDEO_CODEC = "copy"
     DEFAULT_AUDIO_CODEC = "copy"
 
+    FFMPEG_VERSION: Optional[str] = None
+    FFMPEG_VERSION_TIMEOUT = 4.0
+
     @classmethod
     def is_usable(cls, session):
         return cls.command(session) is not None
 
     @classmethod
     def command(cls, session):
-        return cls.resolve_command(session.options.get("ffmpeg-ffmpeg"))
+        with _lock_resolve_command:
+            return cls._resolve_command(
+                session.options.get("ffmpeg-ffmpeg"),
+                not session.options.get("ffmpeg-no-validation"),
+            )
 
     @classmethod
     @lru_cache(maxsize=128)
-    def resolve_command(cls, command: Optional[str] = None) -> Optional[str]:
+    def _resolve_command(cls, command: Optional[str] = None, validate: bool = True) -> Optional[str]:
         if command:
             resolved = which(command)
         else:
@@ -97,9 +109,23 @@ class FFMPEGMuxer(StreamIO):
                 resolved = which(cmd)
                 if resolved:
                     break
+
+        if resolved and validate:
+            log.trace(f"Querying FFmpeg version: {[resolved, '-version']}")  # type: ignore[attr-defined]
+            versionoutput = FFmpegVersionOutput([resolved, "-version"], timeout=cls.FFMPEG_VERSION_TIMEOUT)
+            if not versionoutput.run():
+                log.error("Could not validate FFmpeg!")
+                log.error(f"Unexpected FFmpeg version output while running {[resolved, '-version']}")
+                resolved = None
+            else:
+                cls.FFMPEG_VERSION = versionoutput.version
+                for i, line in enumerate(versionoutput.output):
+                    log.debug(f" {line}" if i > 0 else line)
+
         if not resolved:
-            log.warning("FFmpeg was not found. See the --ffmpeg-ffmpeg option.")
+            log.warning("No valid FFmpeg binary was found. See the --ffmpeg-ffmpeg option.")
             log.warning("Muxing streams is unsupported! Only a subset of the available streams can be returned!")
+
         return resolved
 
     @staticmethod
@@ -213,3 +239,31 @@ class FFMPEGMuxer(StreamIO):
             self.errorlog = None
 
         super().close()
+
+
+class FFmpegVersionOutput(ProcessOutput):
+    # The version output format of the fftools hasn't been changed since n0.7.1 (2011-04-23):
+    # https://github.com/FFmpeg/FFmpeg/blame/n5.1.1/fftools/ffmpeg.c#L110
+    # https://github.com/FFmpeg/FFmpeg/blame/n5.1.1/fftools/opt_common.c#L201
+    # https://github.com/FFmpeg/FFmpeg/blame/c99b93c5d53d8f4a4f1fafc90f3dfc51467ee02e/fftools/cmdutils.c#L1156
+    # https://github.com/FFmpeg/FFmpeg/commit/89b503b55f2b2713f1c3cc8981102c1a7b663281
+    _re_version = re.compile(r"ffmpeg version (?P<version>\S+)")
+
+    def __init__(self, *args, **kwargs):
+        super().__init__(*args, **kwargs)
+        self.version: Optional[str] = None
+        self.output: List[str] = []
+
+    def onexit(self, code: int) -> bool:
+        return code == 0 and self.version is not None
+
+    def onstdout(self, idx: int, line: str) -> Optional[bool]:
+        # only validate the very first line of the stdout stream
+        if idx == 0:
+            match = self._re_version.match(line)
+            # abort if the very first line of stdout doesn't match the expected format
+            if not match:
+                return False
+            self.version = match["version"]
+
+        self.output.append(line)

src/streamlink_cli/argparser.py

@@ -1043,6 +1043,13 @@ def build_parser():
         Example: --ffmpeg-ffmpeg "/usr/local/bin/ffmpeg"
         """
     )
+    transport_ffmpeg.add_argument(
+        "--ffmpeg-no-validation",
+        action="store_true",
+        help="""
+        Disable FFmpeg validation and version logging.
+        """
+    )
     transport_ffmpeg.add_argument(
         "--ffmpeg-verbose",
         action="store_true",
@@ -1263,6 +1270,7 @@ _ARGUMENT_TO_SESSIONOPTION: List[Tuple[str, str, Optional[Callable[[Any], Any]]]
     ("hls_segment_key_uri", "hls-segment-key-uri", None),
     ("hls_audio_select", "hls-audio-select", None),
     ("ffmpeg_ffmpeg", "ffmpeg-ffmpeg", None),
+    ("ffmpeg_no_validation", "ffmpeg-no-validation", None),
     ("ffmpeg_verbose", "ffmpeg-verbose", None),
     ("ffmpeg_verbose_path", "ffmpeg-verbose-path", None),
     ("ffmpeg_fout", "ffmpeg-fout", None),

tests/stream/test_ffmpegmux.py

@@ -5,20 +5,26 @@ from unittest.mock import Mock, call, patch
 import pytest
 
 from streamlink import Streamlink
-from streamlink.stream.ffmpegmux import FFMPEGMuxer
+from streamlink.stream.ffmpegmux import FFMPEGMuxer, FFmpegVersionOutput
+
+
+# noinspection PyProtectedMember
+@pytest.fixture(autouse=True)
+def resolve_command_cache_clear():
+    FFMPEGMuxer._resolve_command.cache_clear()
+    yield
+    FFMPEGMuxer._resolve_command.cache_clear()
 
 
 @pytest.fixture(autouse=True)
-def resolve_command_cache_clear():
-    FFMPEGMuxer.resolve_command.cache_clear()
-    yield
-    FFMPEGMuxer.resolve_command.cache_clear()
+def _logger(caplog: pytest.LogCaptureFixture):
+    caplog.set_level(1, "streamlink")
 
 
 @pytest.fixture
 def session():
     with patch("streamlink.session.Streamlink.load_builtin_plugins"):
-        yield Streamlink()
+        yield Streamlink({"ffmpeg-no-validation": True})
 
 
 class TestCommand:
@@ -51,22 +57,112 @@ class TestCommand:
         with patch("streamlink.stream.ffmpegmux.which", return_value=resolved):
             assert FFMPEGMuxer.is_usable(session) is expected
 
-    def test_log(self, session: Streamlink):
-        with patch("streamlink.stream.ffmpegmux.log") as mock_log, \
-             patch("streamlink.stream.ffmpegmux.which", return_value=None):
+    def test_log(self, caplog: pytest.LogCaptureFixture, session: Streamlink):
+        with patch("streamlink.stream.ffmpegmux.which", return_value=None):
             assert not FFMPEGMuxer.is_usable(session)
-            assert mock_log.warning.call_args_list == [
-                call("FFmpeg was not found. See the --ffmpeg-ffmpeg option."),
-                call("Muxing streams is unsupported! Only a subset of the available streams can be returned!"),
+            assert [(record.module, record.levelname, record.message) for record in caplog.records] == [
+                (
+                    "ffmpegmux",
+                    "warning",
+                    "No valid FFmpeg binary was found. See the --ffmpeg-ffmpeg option.",
+                ),
+                (
+                    "ffmpegmux",
+                    "warning",
+                    "Muxing streams is unsupported! Only a subset of the available streams can be returned!",
+                ),
             ]
             assert not FFMPEGMuxer.is_usable(session)
-            assert len(mock_log.warning.call_args_list) == 2
+            assert len(caplog.records) == 2
 
-    def test_no_log(self, session: Streamlink):
-        with patch("streamlink.stream.ffmpegmux.log") as mock_log, \
-             patch("streamlink.stream.ffmpegmux.which", return_value="foo"):
+    def test_no_log(self, caplog: pytest.LogCaptureFixture, session: Streamlink):
+        with patch("streamlink.stream.ffmpegmux.which", return_value="foo"):
             assert FFMPEGMuxer.is_usable(session)
-            assert not mock_log.warning.call_args_list
+            assert not caplog.records
+
+    def test_validate_success(self, caplog: pytest.LogCaptureFixture, session: Streamlink):
+        session.options.update({"ffmpeg-no-validation": False})
+
+        class MyFFmpegVersionOutput(FFmpegVersionOutput):
+            def run(self):
+                self.onstdout(0, "ffmpeg version 0.0.0 suffix")
+                self.onstdout(1, "foo")
+                self.onstdout(2, "bar")
+                return True
+
+        with patch("streamlink.stream.ffmpegmux.which", return_value="/usr/bin/ffmpeg"), \
+             patch("streamlink.stream.ffmpegmux.FFmpegVersionOutput", side_effect=MyFFmpegVersionOutput) as mock_versionoutput:
+            result = FFMPEGMuxer.command(session)
+
+        assert result == "/usr/bin/ffmpeg"
+        assert mock_versionoutput.call_args_list == [
+            call(["/usr/bin/ffmpeg", "-version"], timeout=4.0),
+        ]
+        assert [(record.module, record.levelname, record.message) for record in caplog.records] == [
+            ("ffmpegmux", "trace", "Querying FFmpeg version: ['/usr/bin/ffmpeg', '-version']"),
+            ("ffmpegmux", "debug", "ffmpeg version 0.0.0 suffix"),
+            ("ffmpegmux", "debug", " foo"),
+            ("ffmpegmux", "debug", " bar"),
+        ]
+
+    def test_validate_failure(self, caplog: pytest.LogCaptureFixture, session: Streamlink):
+        session.options.update({"ffmpeg-no-validation": False})
+
+        class MyFFmpegVersionOutput(FFmpegVersionOutput):
+            def run(self):
+                return False
+
+        with patch("streamlink.stream.ffmpegmux.which", return_value="/usr/bin/ffmpeg"), \
+             patch("streamlink.stream.ffmpegmux.FFmpegVersionOutput", side_effect=MyFFmpegVersionOutput) as mock_versionoutput:
+            result = FFMPEGMuxer.command(session)
+
+        assert result is None
+        assert mock_versionoutput.call_args_list == [
+            call(["/usr/bin/ffmpeg", "-version"], timeout=4.0),
+        ]
+        assert [(record.module, record.levelname, record.message) for record in caplog.records] == [
+            ("ffmpegmux", "trace", "Querying FFmpeg version: ['/usr/bin/ffmpeg', '-version']"),
+            ("ffmpegmux", "error", "Could not validate FFmpeg!"),
+            ("ffmpegmux", "error", "Unexpected FFmpeg version output while running ['/usr/bin/ffmpeg', '-version']"),
+            ("ffmpegmux", "warning", "No valid FFmpeg binary was found. See the --ffmpeg-ffmpeg option."),
+            ("ffmpegmux", "warning", "Muxing streams is unsupported! Only a subset of the available streams can be returned!"),
+        ]
+
+
+class TestFFmpegVersionOutput:
+    @pytest.fixture
+    def output(self):
+        output = FFmpegVersionOutput(["/usr/bin/ffmpeg", "-version"], timeout=1.0)
+        assert output.command == ["/usr/bin/ffmpeg", "-version"]
+        assert output.timeout == 1.0
+        assert output.output == []
+        assert output.version is None
+
+        return output
+
+    def test_success(self, output: FFmpegVersionOutput):
+        output.onstdout(0, "ffmpeg version 0.0.0 suffix")
+        assert output.output == ["ffmpeg version 0.0.0 suffix"]
+        assert output.version == "0.0.0"
+
+        output.onstdout(1, "foo")
+        output.onstdout(2, "bar")
+        assert output.output == ["ffmpeg version 0.0.0 suffix", "foo", "bar"]
+        assert output.version == "0.0.0"
+
+        assert output.onexit(0)
+
+    def test_failure_stdout(self, output: FFmpegVersionOutput):
+        output.onstdout(0, "invalid")
+        assert output.output == []
+        assert output.version is None
+        assert not output.onexit(0)
+
+    def test_failure_exitcode(self, output: FFmpegVersionOutput):
+        output.onstdout(0, "ffmpeg version 0.0.0 suffix")
+        assert output.output == ["ffmpeg version 0.0.0 suffix"]
+        assert output.version == "0.0.0"
+        assert not output.onexit(1)
 
 
 class TestOpen: