openvibers/openvibe.media Commits

Clips: keep ffmpeg's error, widen the cut budget, allow re-cutting

OP OpenVibers committed 18 Aug 2026 · 09073274ae · 2 files, +78 −6

12 clips failed in 24h, all logging the same useless line: "ffmpeg cut failed".
The cutter spawned with stdio:'ignore', so ffmpeg's stderr was thrown away and
the only way to learn anything was to reproduce the command by hand — which
succeeded in 11s, proving the command was fine and the failures were
environmental.

They clustered (19:01:57/02:03/02:09, 19:11:54/11:59) while the box was under
heavy load. libvpx measured ~3.3x realtime idle, so a 25s clip takes ~8s alone
but several times that when encodes overlap. The old budget of dur*2 + 40s left
almost no headroom, and three concurrent encodes on a 4-core box that also runs
live x264 blew straight through it.

  - capture stderr and report ffmpeg's own last lines, plus whether it timed out
    or exited non-zero
  - budget dur*8 + 90s (remote) / 45s (local); this is a background job with no
    deadline, so being generous costs nothing
  - default CLIP_MAX_CONCURRENT_FFMPEG 3 -> 2

Add POST /clips/:id/recut. The row already carries vod_id and the timestamps, so
a failure is recoverable — previously a failed clip stayed broken permanently
with no retry path at all.

Co-Authored-By: Claude Opus 5 <[email protected]>
Claude-Session: https://claude.ai/code/session_01Xw6Sf5zzSALw8m93XNu5JE

Changes

ddiff --git a/server/vod/clip-cutter.js b/server/vod/clip-cutter.js
iindex 5c986ae..0b9920e 100644
---- a/server/vod/clip-cutter.js
++++ b/server/vod/clip-cutter.js
@@@ -15,7 +15,10 @@ const db = require('../db/database');
const config = require('../config');
const CLIPS_DIR = path.resolve(config.vod.clipsPath);
--const MAX_CONCURRENT = parseInt(process.env.CLIP_MAX_CONCURRENT_FFMPEG || '3', 10);
++// libvpx is SLOW — measured at ~3.3x realtime on an idle box, so a 25s clip takes ~8s
++// alone but several times that when encodes overlap. Three at once on a 4-core box that
++// also runs live x264 and whisper is how clips ended up timing out in batches.
++const MAX_CONCURRENT = parseInt(process.env.CLIP_MAX_CONCURRENT_FFMPEG || '2', 10);
let _active = 0;
function _ffprobe(file) {
@@@ -53,6 +56,9 @@ async function cutClipFile({ source, startTime, duration }) {
const outPath = path.join(CLIPS_DIR, filename);
_active++;
++ let timedOut = false;
++ let exitCode = null;
++ const _stderrRef = { get: () => '' };
// Re-encode the (short) clip instead of stream-copying. `-ss` before `-i`
// is a fast seek to the nearest keyframe, and because we re-encode, ffmpeg
// then decodes to the EXACT requested start — the clip begins precisely
@@@ -66,13 +72,31 @@ async function cutClipFile({ source, startTime, duration }) {
'-force_key_frames', 'expr:gte(t,n_forced*2)', '-c:a', 'libopus', '-b:a', '128k',
'-avoid_negative_ts', 'make_zero', '-f', 'webm', outPath,
];
-- const ff = spawn('ffmpeg', args, { stdio: 'ignore' });
-- const to = setTimeout(() => { try { ff.kill('SIGKILL'); } catch { /* */ } resolve(false); }, Math.round(dur) * 2000 + (isUrl ? 40000 : 20000));
-- ff.on('close', (code) => { clearTimeout(to); resolve(code === 0); });
-- ff.on('error', () => { clearTimeout(to); resolve(false); });
++ // Keep stderr. It used to be discarded, so every failure surfaced as the useless
++ // string "ffmpeg cut failed" and the only way to learn anything was to reproduce
++ // the command by hand.
++ const ff = spawn('ffmpeg', args, { stdio: ['ignore', 'ignore', 'pipe'] });
++ let errTail = '';
++ ff.stderr.on('data', (d) => { errTail = (errTail + d).slice(-4000); });
++ // Budget generously: this is a background job with no deadline, and the old
++ // dur*2 + 40s budget was tight enough that a burst of concurrent encodes on a
++ // busy box blew through it — which is exactly how a batch of clips failed at once.
++ const budgetMs = Math.round(dur) * 8000 + (isUrl ? 90000 : 45000);
++ const to = setTimeout(() => { timedOut = true; try { ff.kill('SIGKILL'); } catch { /* */ } resolve(false); }, budgetMs);
++ ff.on('close', (code) => { clearTimeout(to); exitCode = code; resolve(code === 0); });
++ ff.on('error', (e) => { clearTimeout(to); errTail += `\nspawn error: ${e.message}`; resolve(false); });
++ _stderrRef.get = () => errTail;
}).finally(() => { _active = Math.max(0, _active - 1); });
-- if (!ok) { try { fs.existsSync(outPath) && fs.unlinkSync(outPath); } catch { /* */ } return { ok: false, error: 'ffmpeg cut failed' }; }
++ if (!ok) {
++ try { fs.existsSync(outPath) && fs.unlinkSync(outPath); } catch { /* */ }
++ // Surface ffmpeg's own last words — the real reason, not a generic label.
++ const tail = String(_stderrRef.get() || '').split('\n').filter(Boolean).slice(-3).join(' | ').slice(0, 400);
++ const why = timedOut
++ ? `ffmpeg timed out after ${Math.round((Math.round(dur) * 8000 + (isUrl ? 90000 : 45000)) / 1000)}s`
++ : `ffmpeg exited ${exitCode}`;
++ return { ok: false, error: tail ? `${why}: ${tail}` : why };
++ }
// Validate real decodable footage (a seek near EOF can yield a header-only file).
const pi = await _ffprobe(outPath);
ddiff --git a/server/vod/clips-routes.js b/server/vod/clips-routes.js
iindex 562124e..4aac181 100644
---- a/server/vod/clips-routes.js
++++ b/server/vod/clips-routes.js
@@@ -310,6 +310,54 @@ router.get('/:id', tenantAuth({ allowUser: true }), (req, res) => {
});
// ── Update (title / visibility) ──────────────────────────────
++/**
++ * Re-cut a clip whose cut failed. The row already carries everything needed
++ * (vod_id, start_time, end_time), so a failure is recoverable rather than
++ * permanent — previously a failed clip stayed broken forever with no retry path,
++ * and the viewer was shown "the server is cutting your clip" indefinitely.
++ */
++router.post('/:id/recut', tenantAuth(), async (req, res) => {
++ try {
++ const clipId = parseInt(req.params.id, 10);
++ const clip = db.getClipById(clipId);
++ if (!clip || clip.app_id !== req.appId) return res.status(404).json({ error: 'Clip not found' });
++ if (clip.status === 'processing') return res.status(409).json({ error: 'Clip is already being cut' });
++ if (!clip.vod_id) return res.status(422).json({ error: 'Clip has no source VOD to re-cut from' });
++
++ const vod = db.get('SELECT * FROM vods WHERE id = ?', [clip.vod_id]);
++ if (!vod) return res.status(404).json({ error: 'Source VOD no longer exists' });
++
++ const vodStorage = require('./vod-storage');
++ const source = await vodStorage.resolveMediaSource(vod);
++ if (!source) return res.status(404).json({ error: 'VOD media unavailable (not on disk and no cloud copy)' });
++
++ const startTime = Number(clip.start_time) || 0;
++ const duration = Math.max(1, (Number(clip.end_time) || 0) - startTime);
++ db.run('UPDATE clips SET status = ? WHERE id = ?', ['processing', clipId]);
++ const appId = req.appId;
++
++ (async () => {
++ const cut = await cutter.cutClipFile({ source: source.value, startTime, duration });
++ if (cut.ok) {
++ db.run('UPDATE clips SET file_path = ?, duration_seconds = ?, end_time = ?, status = ? WHERE id = ?',
++ [cut.filePath, cut.duration, startTime + cut.duration, 'ready', clipId]);
++ try { await require('../thumbnails/thumbnail-service').generateClipThumbnail(clipId, cut.filePath); } catch { /* */ }
++ console.log(`[Clips] Clip ${clipId} RE-CUT from vod ${clip.vod_id} (${startTime.toFixed(1)}-${(startTime + cut.duration).toFixed(1)}s)`);
++ sendWebhook(appId, 'clip.ready', clipPublic(db.getClipById(clipId))).catch(() => {});
++ } else {
++ console.warn(`[Clips] Clip ${clipId} re-cut failed: ${cut.error}`);
++ db.run('UPDATE clips SET status = ? WHERE id = ?', ['failed', clipId]);
++ sendWebhook(appId, 'clip.failed', clipPublic(db.getClipById(clipId))).catch(() => {});
++ }
++ })().catch(err => console.error('[Clips] Background re-cut error:', err.message));
++
++ res.status(202).json({ id: clipId, status: 'processing' });
++ } catch (err) {
++ console.error('[Clips] Re-cut error:', err.message);
++ res.status(500).json({ error: 'Failed to re-cut clip' });
++ }
++});
++
router.put('/:id', tenantAuth(), (req, res) => {
try {
const clip = _getClipScoped(req, res);