From 1251613f455cd8dbecd3de256173db2caedce30d Mon Sep 17 00:00:00 2001 From: Alex Shnitman Date: Fri, 21 Aug 2026 16:01:40 +0200 Subject: [PATCH] fix: show the post-download processing phase in the UI (closes #424) yt-dlp reports a download 'finished' as soon as the media bytes have landed, but the ffmpeg work that follows -- merging, re-encoding, chapter splitting, sponsor removal -- routinely takes longer than the download itself. The postprocessor hook only ever looked at MoveFiles and SplitChapters finishing, so that whole phase said nothing: the row sat in the Downloading table on a full, frozen progress bar, and the item counted as neither active nor queued in the header stats. Report a 'postprocessing' status when a postprocessor starts, and reuse the indeterminate bar the UI already runs for 'preparing', labelled so a long re-encode is distinguishable from a stall. Measured on a real download re-encoded with the reporter's FFmpegCopyStream config, the UI now receives: [ 0.27s] downloading moving bar [ 0.28s] finished <- yt-dlp, bytes are down [ 0.28s] postprocessing animated "Post-processing" [13.18s] finished done i.e. 12.9s that used to render as a static 100% bar. The hook is latched off once MoveFiles reports finished, since that branch announces the finished file: a 'postprocessing' arriving afterwards would flip the row back out of its completed state for no reason. It cannot fail the download -- _download puts an unconditional 'finished' once download() returns, so the terminal status is settled either way -- but the flicker and the extra broadcast are both pointless. yt-dlp does run an 'after_move' stage after MoveFiles, though every postprocessor MeTube configures is 'after_filter' or 'post_process', both of which precede it. update_status drops a repeated 'postprocessing': yt-dlp's metaclass wraps run() once per class in a postprocessor's MRO, so one whose subclass overrides run reports started twice -- FFmpegCopyStream did exactly that in the live run, three queued statuses collapsing to a single broadcast. Extracted to _make_postprocessor_hook, mirroring _make_progress_hook, so the ordering above is testable; every new regression test was confirmed to fail with the fix backed out. Co-Authored-By: Claude Opus 5 --- app/tests/test_ytdl_utils.py | 115 ++++++++++++++++++++++++++++++++++- app/ytdl.py | 94 +++++++++++++++++++--------- ui/src/app/app.html | 8 ++- ui/src/app/app.spec.ts | 46 ++++++++++++++ ui/src/app/app.ts | 10 ++- 5 files changed, 240 insertions(+), 33 deletions(-) diff --git a/app/tests/test_ytdl_utils.py b/app/tests/test_ytdl_utils.py index c5363f4..f6198d2 100644 --- a/app/tests/test_ytdl_utils.py +++ b/app/tests/test_ytdl_utils.py @@ -777,6 +777,80 @@ class ProgressThrottleTests(unittest.TestCase): self.assertIn("error", statuses) +class PostprocessorHookTests(unittest.TestCase): + """The postprocessing phase must be visible without ever displacing the + terminal 'finished' status that _post_download_cleanup keys off.""" + + def _hook(self): + dl = _make_test_download() + forwarded = [] + dl.status_queue = types.SimpleNamespace(put=forwarded.append) + return dl._make_postprocessor_hook(), forwarded + + def test_postprocessor_start_reports_the_phase(self): + hook, forwarded = self._hook() + hook({"postprocessor": "VideoConvertor", "status": "started", "info_dict": {}}) + self.assertEqual(forwarded, [{"status": "postprocessing"}]) + + def test_postprocessor_finish_is_not_reported(self): + # Only 'started' moves the UI; a PP finishing says nothing about what + # comes next, and an extra broadcast per PP buys nothing. + hook, forwarded = self._hook() + hook({"postprocessor": "VideoConvertor", "status": "finished", "info_dict": {}}) + self.assertEqual(forwarded, []) + + def test_move_files_still_reports_finished_with_the_final_path(self): + hook, forwarded = self._hook() + hook({ + "postprocessor": "MoveFiles", + "status": "finished", + "info_dict": {"filepath": "/tmp/video.mp4"}, + }) + self.assertEqual(forwarded, [{"status": "finished", "filename": "/tmp/video.mp4"}]) + + def test_nothing_is_reported_after_move_files_finished(self): + # Regression guard: _post_download_cleanup turns any final status other + # than 'finished' into an error, so an 'after_move' postprocessor + # starting up must not overwrite it and fail the download. + hook, forwarded = self._hook() + hook({ + "postprocessor": "MoveFiles", + "status": "finished", + "info_dict": {"filepath": "/tmp/video.mp4"}, + }) + hook({"postprocessor": "SomeAfterMovePP", "status": "started", "info_dict": {}}) + self.assertEqual([item["status"] for item in forwarded], ["finished"]) + + def test_realistic_sequence_ends_finished(self): + hook, forwarded = self._hook() + for pp in ("Merger", "VideoConvertor", "Metadata"): + hook({"postprocessor": pp, "status": "started", "info_dict": {}}) + hook({"postprocessor": pp, "status": "finished", "info_dict": {}}) + hook({"postprocessor": "MoveFiles", "status": "started", "info_dict": {}}) + hook({ + "postprocessor": "MoveFiles", + "status": "finished", + "info_dict": {"filepath": "/tmp/video.mp4"}, + }) + + statuses = [item["status"] for item in forwarded] + self.assertEqual(statuses[-1], "finished") + self.assertEqual(statuses.count("finished"), 1) + self.assertTrue(all(st == "postprocessing" for st in statuses[:-1])) + + def test_split_chapters_still_captures_files_without_a_status(self): + hook, forwarded = self._hook() + hook({ + "postprocessor": "SplitChapters", + "status": "finished", + "info_dict": {"chapters": [{"filepath": "/tmp/ch1.mp4"}, {"filepath": "/tmp/ch2.mp4"}]}, + }) + self.assertEqual( + forwarded, + [{"chapter_file": "/tmp/ch1.mp4"}, {"chapter_file": "/tmp/ch2.mp4"}], + ) + + class CancelProcessGroupTests(unittest.TestCase): # cancel() now sends SIGINT first (so yt-dlp/ffmpeg can finalize the # partial file) and schedules a SIGKILL escalation via the event loop @@ -1202,7 +1276,13 @@ class UpdateStatusFileStatTests(unittest.IsolatedAsyncioTestCase): download.loop = asyncio.get_running_loop() download._executor = ThreadPoolExecutor(max_workers=1) notifier = MagicMock() - notifier.updated = AsyncMock() + # updated() is handed the same DownloadInfo every time, so the status has + # to be copied out when the call happens -- reading it off the recorded + # call args afterwards only ever shows the final value. + notifier.broadcast_statuses = [] + notifier.updated = AsyncMock( + side_effect=lambda info: notifier.broadcast_statuses.append(info.status) + ) download.notifier = notifier stat_calls = [] @@ -1237,3 +1317,36 @@ class UpdateStatusFileStatTests(unittest.IsolatedAsyncioTestCase): self.assertEqual(stat_calls, ["/tmp/v.mp4"]) self.assertIsNone(download.info.size) + + async def test_repeated_postprocessing_status_is_broadcast_once(self): + # yt-dlp's metaclass wraps run() once per class in a postprocessor's MRO, + # so one whose subclass overrides run (FFmpegCopyStream, among others) + # reports 'started' twice. Observed live on a 13s libx264 re-encode. + download, _ = await self._run_update_status([ + {"status": "downloading", "downloaded_bytes": 1}, + {"status": "postprocessing"}, + {"status": "postprocessing"}, + {"status": "postprocessing"}, + {"status": "finished", "filename": "/tmp/v.mp4"}, + ]) + + self.assertEqual( + download.notifier.broadcast_statuses, + ["downloading", "postprocessing", "finished"], + ) + + async def test_postprocessing_is_announced_again_after_the_download_resumes(self): + # An audio download runs pre_process postprocessors before the bytes + # arrive, so 'postprocessing' legitimately appears on both sides of the + # download. Deduping against the live status keeps the second one. + download, _ = await self._run_update_status([ + {"status": "postprocessing"}, + {"status": "downloading", "downloaded_bytes": 1}, + {"status": "postprocessing"}, + {"status": "finished", "filename": "/tmp/v.mp4"}, + ]) + + self.assertEqual( + download.notifier.broadcast_statuses, + ["postprocessing", "downloading", "postprocessing", "finished"], + ) diff --git a/app/ytdl.py b/app/ytdl.py index 9d39853..569250a 100644 --- a/app/ytdl.py +++ b/app/ytdl.py @@ -771,6 +771,59 @@ class Download: return put_status + def _make_postprocessor_hook(self): + # yt-dlp reports the download 'finished' as soon as the media bytes + # have landed, but the ffmpeg work that follows -- merging, + # re-encoding, chapter splitting, sponsor removal -- routinely takes + # longer than the download itself and said nothing until now, leaving + # the row on a full, frozen progress bar for minutes. Report the phase + # so the UI can run its indeterminate bar instead. + # + # Latched off once MoveFiles reports finished: that branch emits the + # terminal 'finished', and _post_download_cleanup turns any other + # final status into an error, so nothing may overwrite it. yt-dlp does + # run an 'after_move' stage after MoveFiles, but every postprocessor + # MeTube configures is 'after_filter' or 'post_process', both of which + # precede it. Each postprocessor emits exactly one started/finished + # pair, so this needs no throttling. + postprocessing_done = False + + def put_status_postprocessor(d): + nonlocal postprocessing_done + if d['postprocessor'] == 'MoveFiles' and d['status'] == 'finished': + postprocessing_done = True + filepath = d['info_dict']['filepath'] + if '__finaldir' in d['info_dict']: + finaldir = d['info_dict']['__finaldir'] + filename = os.path.join(finaldir, os.path.basename(filepath)) + else: + filename = filepath + self.status_queue.put({'status': 'finished', 'filename': filename}) + # For captions-only downloads, yt-dlp may still report a media-like + # filepath in MoveFiles. Capture subtitle outputs explicitly so the + # UI can link to real caption files. + if getattr(self.info, 'download_type', '') == 'captions': + requested_subtitles = d.get('info_dict', {}).get('requested_subtitles', {}) or {} + for subtitle in requested_subtitles.values(): + if isinstance(subtitle, dict) and subtitle.get('filepath'): + self.status_queue.put({'subtitle_file': subtitle['filepath']}) + + # Capture all chapter files when SplitChapters finishes + elif d.get('postprocessor') == 'SplitChapters' and d.get('status') == 'finished': + chapters = d.get('info_dict', {}).get('chapters', []) + if chapters: + for chapter in chapters: + if isinstance(chapter, dict) and 'filepath' in chapter: + log.info(f"Captured chapter file: {chapter['filepath']}") + self.status_queue.put({'chapter_file': chapter['filepath']}) + else: + log.warning("SplitChapters finished but no chapter files found in info_dict") + + elif d.get('status') == 'started' and not postprocessing_done: + self.status_queue.put({'status': 'postprocessing'}) + + return put_status_postprocessor + def _make_youtube_dl(self, params): ydl = _ConfinedYoutubeDL( params=params, @@ -815,35 +868,7 @@ class Download: try: debug_logging = logging.getLogger().isEnabledFor(logging.DEBUG) put_status = self._make_progress_hook() - - def put_status_postprocessor(d): - if d['postprocessor'] == 'MoveFiles' and d['status'] == 'finished': - filepath = d['info_dict']['filepath'] - if '__finaldir' in d['info_dict']: - finaldir = d['info_dict']['__finaldir'] - filename = os.path.join(finaldir, os.path.basename(filepath)) - else: - filename = filepath - self.status_queue.put({'status': 'finished', 'filename': filename}) - # For captions-only downloads, yt-dlp may still report a media-like - # filepath in MoveFiles. Capture subtitle outputs explicitly so the - # UI can link to real caption files. - if getattr(self.info, 'download_type', '') == 'captions': - requested_subtitles = d.get('info_dict', {}).get('requested_subtitles', {}) or {} - for subtitle in requested_subtitles.values(): - if isinstance(subtitle, dict) and subtitle.get('filepath'): - self.status_queue.put({'subtitle_file': subtitle['filepath']}) - - # Capture all chapter files when SplitChapters finishes - elif d.get('postprocessor') == 'SplitChapters' and d.get('status') == 'finished': - chapters = d.get('info_dict', {}).get('chapters', []) - if chapters: - for chapter in chapters: - if isinstance(chapter, dict) and 'filepath' in chapter: - log.info(f"Captured chapter file: {chapter['filepath']}") - self.status_queue.put({'chapter_file': chapter['filepath']}) - else: - log.warning("SplitChapters finished but no chapter files found in info_dict") + put_status_postprocessor = self._make_postprocessor_hook() ytdl_params = { 'quiet': not debug_logging, @@ -1090,6 +1115,17 @@ class Download: self.info.size = file_size continue + # yt-dlp's postprocessor metaclass wraps run() once per class in the + # MRO, so a postprocessor whose subclass overrides run reports + # started twice (FFmpegCopyStream, among others). Nothing has changed + # between the two, so drop the repeat rather than re-encode and + # rebroadcast the same state to every connected client. Compared + # against the live status, not a flag in the hook, so the phase is + # still announced when a pre_process postprocessor ran before the + # download and 'downloading' came in between. + if status['status'] == 'postprocessing' and self.info.status == 'postprocessing': + continue + self.info.status = status['status'] self.info.msg = status.get('msg') if 'downloaded_bytes' in status: diff --git a/ui/src/app/app.html b/ui/src/app/app.html index f9b6dbb..f613b4b 100644 --- a/ui/src/app/app.html +++ b/ui/src/app/app.html @@ -732,8 +732,12 @@ } } @else { - + + @if (download.value.status === 'postprocessing') { + Post-processing + } + } diff --git a/ui/src/app/app.spec.ts b/ui/src/app/app.spec.ts index 5156a3d..da4e0b4 100644 --- a/ui/src/app/app.spec.ts +++ b/ui/src/app/app.spec.ts @@ -473,4 +473,50 @@ describe('App', () => { expect(app.buildChapterDownloadLink(audio, 'ch1.mp3')).toBe('audio_download/ch1.mp3'); }); }); + + // Issue #424: ffmpeg work after the bytes land (merge, re-encode, split) used + // to leave the row on a full, frozen bar with the item counted as neither + // active nor queued. + describe('post-processing is visible (#424)', () => { + const queueEntry = (status: string): Download => ({ + id: 'vid1', + title: 'Test', + url: 'https://example.com/v', + download_type: 'video', + quality: 'best', + format: 'any', + folder: '', + custom_name_prefix: '', + playlist_item_limit: 0, + status, + msg: '', + percent: 100, + speed: 0, + eta: 0, + filename: '', + checked: false, + } as Download); + + it('runs the bar indeterminate while preparing or post-processing', () => { + const app = TestBed.createComponent(App).componentInstance; + expect(app.isIndeterminate(queueEntry('preparing'))).toBe(true); + expect(app.isIndeterminate(queueEntry('postprocessing'))).toBe(true); + expect(app.isIndeterminate(queueEntry('downloading'))).toBe(false); + expect(app.isIndeterminate(queueEntry('pending'))).toBe(false); + }); + + it('labels the bar and counts the item as active', () => { + // The component subscribes to queueChanged on construction, so the entry + // has to be announced after it exists or updateMetrics never runs. + const fixture = TestBed.createComponent(App); + downloads.queue.set('https://example.com/v', queueEntry('postprocessing')); + downloads.queueChanged.next(); + fixture.detectChanges(); + + expect((fixture.nativeElement as HTMLElement).textContent).toContain('Post-processing'); + expect(fixture.componentInstance.activeDownloads).toBe(1); + expect(fixture.componentInstance.queuedDownloads).toBe(0); + }); + }); + }); diff --git a/ui/src/app/app.ts b/ui/src/app/app.ts index 4aac535..caf800e 100644 --- a/ui/src/app/app.ts +++ b/ui/src/app/app.ts @@ -1184,6 +1184,14 @@ export class App implements AfterViewInit, OnInit, OnDestroy { this.downloads.startById([id]).subscribe((res) => this.handleActionResult(res, 'Start download failed')); } + // 'preparing' (yt-dlp starting up) and 'postprocessing' (ffmpeg merging, + // re-encoding or splitting once the bytes have landed) both have real work in + // flight with no percentage to report, so the bar runs animated at full width + // instead of showing a number that cannot move. + isIndeterminate(download: Download): boolean { + return download.status === 'preparing' || download.status === 'postprocessing'; + } + liveCountdownSeconds(download: Download): number | null { const ts = download.live_release_timestamp; if (ts == null || download.status !== 'scheduled') { @@ -1697,7 +1705,7 @@ export class App implements AfterViewInit, OnInit, OnDestroy { if (download.status === 'downloading') { active++; speed += download.speed || 0; - } else if (download.status === 'preparing') { + } else if (download.status === 'preparing' || download.status === 'postprocessing') { active++; } else if (download.status === 'pending' || download.status === 'scheduled') { queued++;