mirror of
https://github.com/alexta69/metube.git
synced 2026-09-21 21:45:04 +00:00
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 <noreply@anthropic.com>
This commit is contained in:
@@ -777,6 +777,80 @@ class ProgressThrottleTests(unittest.TestCase):
|
|||||||
self.assertIn("error", statuses)
|
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):
|
class CancelProcessGroupTests(unittest.TestCase):
|
||||||
# cancel() now sends SIGINT first (so yt-dlp/ffmpeg can finalize the
|
# cancel() now sends SIGINT first (so yt-dlp/ffmpeg can finalize the
|
||||||
# partial file) and schedules a SIGKILL escalation via the event loop
|
# 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.loop = asyncio.get_running_loop()
|
||||||
download._executor = ThreadPoolExecutor(max_workers=1)
|
download._executor = ThreadPoolExecutor(max_workers=1)
|
||||||
notifier = MagicMock()
|
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
|
download.notifier = notifier
|
||||||
|
|
||||||
stat_calls = []
|
stat_calls = []
|
||||||
@@ -1237,3 +1317,36 @@ class UpdateStatusFileStatTests(unittest.IsolatedAsyncioTestCase):
|
|||||||
|
|
||||||
self.assertEqual(stat_calls, ["/tmp/v.mp4"])
|
self.assertEqual(stat_calls, ["/tmp/v.mp4"])
|
||||||
self.assertIsNone(download.info.size)
|
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"],
|
||||||
|
)
|
||||||
|
|||||||
+65
-29
@@ -771,6 +771,59 @@ class Download:
|
|||||||
|
|
||||||
return put_status
|
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):
|
def _make_youtube_dl(self, params):
|
||||||
ydl = _ConfinedYoutubeDL(
|
ydl = _ConfinedYoutubeDL(
|
||||||
params=params,
|
params=params,
|
||||||
@@ -815,35 +868,7 @@ class Download:
|
|||||||
try:
|
try:
|
||||||
debug_logging = logging.getLogger().isEnabledFor(logging.DEBUG)
|
debug_logging = logging.getLogger().isEnabledFor(logging.DEBUG)
|
||||||
put_status = self._make_progress_hook()
|
put_status = self._make_progress_hook()
|
||||||
|
put_status_postprocessor = self._make_postprocessor_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")
|
|
||||||
|
|
||||||
ytdl_params = {
|
ytdl_params = {
|
||||||
'quiet': not debug_logging,
|
'quiet': not debug_logging,
|
||||||
@@ -1090,6 +1115,17 @@ class Download:
|
|||||||
self.info.size = file_size
|
self.info.size = file_size
|
||||||
continue
|
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.status = status['status']
|
||||||
self.info.msg = status.get('msg')
|
self.info.msg = status.get('msg')
|
||||||
if 'downloaded_bytes' in status:
|
if 'downloaded_bytes' in status:
|
||||||
|
|||||||
+6
-2
@@ -732,8 +732,12 @@
|
|||||||
}
|
}
|
||||||
</span>
|
</span>
|
||||||
} @else {
|
} @else {
|
||||||
<ngb-progressbar height="1.5rem" [showValue]="download.value.status !== 'preparing'" [striped]="download.value.status === 'preparing'" [animated]="download.value.status === 'preparing'" type="success"
|
<ngb-progressbar height="1.5rem" [showValue]="!isIndeterminate(download.value)" [striped]="isIndeterminate(download.value)" [animated]="isIndeterminate(download.value)" type="success"
|
||||||
[value]="download.value.status === 'preparing' ? 100 : download.value.percent" class="download-progressbar" />
|
[value]="isIndeterminate(download.value) ? 100 : download.value.percent" class="download-progressbar">
|
||||||
|
@if (download.value.status === 'postprocessing') {
|
||||||
|
<span>Post-processing</span>
|
||||||
|
}
|
||||||
|
</ngb-progressbar>
|
||||||
}
|
}
|
||||||
</div>
|
</div>
|
||||||
</td>
|
</td>
|
||||||
|
|||||||
@@ -473,4 +473,50 @@ describe('App', () => {
|
|||||||
expect(app.buildChapterDownloadLink(audio, 'ch1.mp3')).toBe('audio_download/ch1.mp3');
|
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);
|
||||||
|
});
|
||||||
|
});
|
||||||
|
|
||||||
});
|
});
|
||||||
|
|||||||
+9
-1
@@ -1184,6 +1184,14 @@ export class App implements AfterViewInit, OnInit, OnDestroy {
|
|||||||
this.downloads.startById([id]).subscribe((res) => this.handleActionResult(res, 'Start download failed'));
|
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 {
|
liveCountdownSeconds(download: Download): number | null {
|
||||||
const ts = download.live_release_timestamp;
|
const ts = download.live_release_timestamp;
|
||||||
if (ts == null || download.status !== 'scheduled') {
|
if (ts == null || download.status !== 'scheduled') {
|
||||||
@@ -1697,7 +1705,7 @@ export class App implements AfterViewInit, OnInit, OnDestroy {
|
|||||||
if (download.status === 'downloading') {
|
if (download.status === 'downloading') {
|
||||||
active++;
|
active++;
|
||||||
speed += download.speed || 0;
|
speed += download.speed || 0;
|
||||||
} else if (download.status === 'preparing') {
|
} else if (download.status === 'preparing' || download.status === 'postprocessing') {
|
||||||
active++;
|
active++;
|
||||||
} else if (download.status === 'pending' || download.status === 'scheduled') {
|
} else if (download.status === 'pending' || download.status === 'scheduled') {
|
||||||
queued++;
|
queued++;
|
||||||
|
|||||||
Reference in New Issue
Block a user