test_ffmpeg_output_summary.py 8.1 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185
  1. """ffmpeg's diagnosis survives the log line, and its banner does not (#2968).
  2. ffmpeg prints ~20 lines of version and build banner first and its actual error
  3. last, so the ``stderr[:200]`` most call sites used kept the banner and dropped
  4. the error. The reporter's H2D logged twelve capture failures that way; every
  5. one of them was the same 200 characters of ``--prefix=/usr --extra-version=``
  6. and none of them said why the capture failed.
  7. #925 already solved this for the camera streaming endpoint. These tests cover
  8. the shared module the other seven call sites now go through, and the two things
  9. that were only ever true of the private copy: it takes bytes, and it masks
  10. credentials for callers that never did.
  11. """
  12. import inspect
  13. import pytest
  14. from backend.app.utils.ffmpeg_output import NO_FFMPEG_OUTPUT, summarize_ffmpeg_stderr
  15. # Verbatim from the reporter's log, trimmed to the width the old truncation
  16. # allowed through. The point of the fixture is that 200 characters of it carry
  17. # no information at all.
  18. _REAL_BANNER = """ffmpeg version 7.1.4-0+deb13u1 Copyright (c) 2000-2026 the FFmpeg developers
  19. built with gcc 14 (Debian 14.2.0-19)
  20. configuration: --prefix=/usr --extra-version=0+deb13u1 --toolchain=hardened --enable-gpl
  21. libavutil 59. 39.100 / 59. 39.100
  22. libavcodec 61. 19.101 / 61. 19.101
  23. libavformat 61. 7.100 / 61. 7.100
  24. libavdevice 61. 3.100 / 61. 3.100
  25. libavfilter 10. 4.100 / 10. 4.100
  26. libswscale 8. 3.100 / 8. 3.100
  27. libswresample 5. 3.100 / 5. 3.100
  28. libpostproc 58. 3.100 / 58. 3.100
  29. """
  30. class TestTheDiagnosisSurvives:
  31. def test_the_error_is_kept_and_the_banner_is_not(self):
  32. """The whole point: the last line, not the first 200 characters."""
  33. stderr = _REAL_BANNER + "[rtsp @ 0x5f] method DESCRIBE failed: 401 Unauthorized\n"
  34. result = summarize_ffmpeg_stderr(stderr)
  35. assert "method DESCRIBE failed: 401 Unauthorized" in result
  36. assert "ffmpeg version" not in result
  37. assert "--prefix=/usr" not in result
  38. def test_the_old_truncation_would_have_kept_none_of_it(self):
  39. """Guards the claim the fix rests on rather than asserting it in prose:
  40. 200 characters from the front of a real failure is banner only."""
  41. stderr = _REAL_BANNER + "[rtsp @ 0x5f] method DESCRIBE failed: 401 Unauthorized\n"
  42. assert "DESCRIBE" not in stderr[:200]
  43. def test_input_analysis_is_kept(self):
  44. """Indented, but not banner. ``Duration:`` and ``Stream #0:0`` explain
  45. the error above them and are the reason the match is on exact prefixes
  46. rather than on leading whitespace."""
  47. stderr = _REAL_BANNER + (
  48. "Input #0, rtsp, from 'rtsp://192.0.2.1:322/streaming/live/1':\n"
  49. " Duration: N/A, start: 0.000000, bitrate: N/A\n"
  50. " Stream #0:0: Video: h264, yuv420p, 1920x1080\n"
  51. "Output file is empty, nothing was encoded\n"
  52. )
  53. result = summarize_ffmpeg_stderr(stderr)
  54. assert "Duration: N/A" in result
  55. assert "Stream #0:0: Video: h264" in result
  56. assert "Output file is empty" in result
  57. def test_only_the_last_lines_are_kept(self):
  58. """A chatty decoder must not rotate the log file on one failure."""
  59. stderr = _REAL_BANNER + "\n".join(f"error line {i}" for i in range(40))
  60. lines = summarize_ffmpeg_stderr(stderr).splitlines()
  61. assert len(lines) == 10
  62. assert lines[-1] == "error line 39"
  63. def test_a_banner_only_failure_says_so(self):
  64. """Empty, so the caller substitutes a phrase. ``failed: `` with nothing
  65. after it reads like a truncation bug rather than a silent printer."""
  66. assert summarize_ffmpeg_stderr(_REAL_BANNER) == ""
  67. assert (summarize_ffmpeg_stderr(_REAL_BANNER) or NO_FFMPEG_OUTPUT) == NO_FFMPEG_OUTPUT
  68. class TestWhatTheCallSitesUsedToGetWrong:
  69. def test_bytes_are_accepted(self):
  70. """Every call site held bytes and decoded them itself."""
  71. assert "Connection refused" in summarize_ffmpeg_stderr(b"rtsp://192.0.2.1: Connection refused\n")
  72. def test_undecodable_bytes_do_not_raise(self):
  73. """ffmpeg copies stream fragments into its messages, so a bare
  74. ``.decode()`` could raise UnicodeDecodeError while reporting an
  75. unrelated failure -- losing the diagnosis to a second exception."""
  76. result = summarize_ffmpeg_stderr(b"\xff\xfe broken input\nInvalid data found\n")
  77. assert "Invalid data found" in result
  78. def test_the_access_code_is_masked(self):
  79. """ffmpeg echoes its input URL back, and four of the call sites logged
  80. it unmasked. The mask is part of the summary so it cannot be skipped."""
  81. stderr = b"Error opening input file rtsp://bblp:12345678@192.0.2.1:322/streaming/live/1.\n"
  82. result = summarize_ffmpeg_stderr(stderr)
  83. assert "12345678" not in result
  84. assert "[REDACTED]" in result
  85. # Host and user survive, or the line stops being useful for diagnosis.
  86. assert "192.0.2.1:322" in result
  87. assert "bblp" in result
  88. def test_a_credential_masked_before_the_cut_not_after(self):
  89. """Truncating first would leave a URL with no ``@`` for the pattern to
  90. anchor on, and the secret in the log."""
  91. stderr = "\n".join(f"noise {i}" for i in range(30))
  92. stderr += "\nOpening rtsp://user:hunter2@192.0.2.1:322/live and 40 more characters of tail\n"
  93. result = summarize_ffmpeg_stderr(stderr)
  94. assert "hunter2" not in result
  95. @pytest.mark.parametrize("empty", ["", None, b""])
  96. def test_nothing_in_nothing_out(self, empty):
  97. assert summarize_ffmpeg_stderr(empty) == ""
  98. def test_a_single_enormous_line_is_bounded(self):
  99. """Ten lines only bounds the record if the lines are sane, and ffmpeg
  100. quotes back what the peer sent it. The tail is what is kept."""
  101. stderr = _REAL_BANNER + "x" * 50_000 + " Connection refused\n"
  102. result = summarize_ffmpeg_stderr(stderr)
  103. assert len(result) < 2_100
  104. assert result.endswith("Connection refused")
  105. assert result.startswith("...")
  106. def test_an_ordinary_diagnosis_is_never_trimmed(self):
  107. """The ceiling must not be reachable by real ffmpeg output."""
  108. stderr = _REAL_BANNER + "\n".join(f"[rtsp @ 0x5f] error line {i}" for i in range(10))
  109. assert not summarize_ffmpeg_stderr(stderr).startswith("...")
  110. class TestEveryCallSiteGoesThroughIt:
  111. """The defect was seven copies of the same truncation, not one bad line.
  112. Asserted against the source because the alternative -- driving all seven
  113. subprocesses -- tests ffmpeg, and because the failure mode being guarded is
  114. somebody adding an eighth.
  115. """
  116. @pytest.mark.parametrize(
  117. "module_path",
  118. [
  119. "backend.app.services.camera",
  120. "backend.app.services.external_camera",
  121. "backend.app.services.layer_timelapse",
  122. "backend.app.services.timelapse_processor",
  123. "backend.app.services.archive",
  124. "backend.app.api.routes.camera",
  125. ],
  126. )
  127. def test_no_module_truncates_stderr_by_hand(self, module_path):
  128. import importlib
  129. source = inspect.getsource(importlib.import_module(module_path))
  130. for lineno, raw in enumerate(source.splitlines(), 1):
  131. # Comments discuss the defect by name -- this file's own fix notes
  132. # do -- so only what executes is checked.
  133. line = raw.split("#", 1)[0]
  134. if "stderr" not in line:
  135. continue
  136. assert "stderr.decode()[:" not in line, f"{module_path}:{lineno} truncates stderr from the front"
  137. assert "stderr_text[:" not in line, f"{module_path}:{lineno} truncates stderr from the front"
  138. assert 'stderr.decode(errors="replace")[:' not in line, (
  139. f"{module_path}:{lineno} truncates stderr from the front"
  140. )
  141. # A bare decode is the other half of the defect: it can raise
  142. # UnicodeDecodeError while reporting an unrelated failure, and it
  143. # leaves the input URL's credentials unmasked.
  144. assert "stderr.decode()" not in line, f"{module_path}:{lineno} decodes stderr by hand"