Video - Always check artwork/nfo for recovery & improve error logging

Inrixia · Oct 30, 2024 · 1d7661c · 1d7661c
1 parent f96cc3a
commit 1d7661c
Show file tree

Hide file tree

Showing 6 changed files with 109 additions and 119 deletions.
diff --git a/package.json b/package.json
@@ -8,7 +8,7 @@
     "start": "pnpm run tsc && node ./dist/float.js",
     "startHeadless": "pnpm run tsc && node ./dist/float.js --headless",
     "checkLint": "eslint ./src",
-    "sanity": "pnpm run checkLint && pnpm run test-esm && pnpm run build-windows-latest && pnpm run test-windows-latest",
+    "sanity": "pnpm run checkLint && pnpm run test-esm && pnpm run build && pnpm run test",
     "test-esm": "pnpm run tsc && node ./dist/float.js --sanityCheck",
     "test": "./build/float --sanityCheck",
     "makeBlob": "node --experimental-sea-config ./sea-config.json",

diff --git a/src/float.ts b/src/float.ts
@@ -22,7 +22,7 @@ const downloadNewVideos = async () => {
 	const inProgress = [];
 
 	// Fetch content posts from seek and destroy guids
-	let contentPosts: Promise<ContentPost>[] = [];
+	const contentPosts: Promise<ContentPost>[] = [];
 	while (settings.floatplane.seekAndDestroy.length > 0) {
 		const guid = settings.floatplane.seekAndDestroy.pop();
 		if (guid === undefined) continue;

diff --git a/src/lib/Video.ts b/src/lib/Video.ts
@@ -23,6 +23,7 @@ import { updatePlex } from "./helpers/updatePlex.js";
 
 import { ProgressHeadless } from "./logging/ProgressConsole.js";
 import { ProgressBars } from "./logging/ProgressBars.js";
+import { withContext } from "./logging/ProgressLogger.js";
 
 const exec = promisify(execCallback);
 const sleep = promisify(setTimeout);
@@ -67,7 +68,7 @@ export class Video extends Attachment {
 
 	public static State = VideoState;
 
-	private static readonly MaxRetries = 5;
+	private static readonly MaxRetries = 1;
 	private static readonly DownloadThreads = 8;
 
 	private static readonly DownloadSemaphore = new Semaphore(this.DownloadThreads);
@@ -76,6 +77,7 @@ export class Video extends Attachment {
 	private static readonly ThrottleGroup = settings.maxDownloadSpeed > -1 ? new ThrottleGroup(Video.ThrottleOptions) : undefined;
 
 	private static readonly ProgressLogger: typeof ProgressHeadless | typeof ProgressBars = args.headless ? ProgressHeadless : ProgressBars;
+	private readonly logger = new Video.ProgressLogger(this.videoTitle);
 
 	// Static cache of instances
 	public static readonly Videos: Record<string, Video> = {};
@@ -92,118 +94,98 @@ export class Video extends Attachment {
 	}
 
 	public async download() {
-		if ((await this.getState()) === Video.State.Muxed) return;
-		const logger = new Video.ProgressLogger(this.videoTitle);
-		promQueued.inc();
 		await Video.DownloadSemaphore.obtain();
-		logger.start();
-		for (let retries = 1; retries < Video.MaxRetries + 1; retries++) {
-			try {
-				switch (await this.getState()) {
-					case Video.State.Missing: {
-						logger.log("Waiting on delivery cdn...");
-						const downloadRequest = await this.getVideoStream(settings.floatplane.videoResolution);
-
-						// Pipe the download to the file once response starts
-						const writeStream = createWriteStream(this.partialPath);
-
-						// Throttle if enabled
-						if (Video.ThrottleGroup) {
-							// @ts-expect-error Type is wrong, this needs to be called with no arguments
-							const throttle = Video.ThrottleGroup.throttle();
-							downloadRequest.pipe(throttle).pipe(writeStream);
-						} else downloadRequest.pipe(writeStream);
-
-						let downloadedBytes = 0;
-						const onDownloadProgress = (progress: Progress) => {
-							const bytesSinceLast = progress.transferred - downloadedBytes;
-							downloadedBytes = progress.transferred;
-							promDownloadedBytes.inc(bytesSinceLast);
-							logger.onDownloadProgress(downloadRequest.downloadProgress, bytesSinceLast);
-						};
-
-						let downloadInterval: NodeJS.Timeout;
-						downloadRequest.once("downloadProgress", (downloadProgress: Progress) => {
-							logger.log("Download started!");
-							downloadInterval = setInterval(() => onDownloadProgress(downloadRequest.downloadProgress), 250);
-							onDownloadProgress(downloadProgress);
-						});
-
-						await new Promise((res, rej) => {
-							downloadRequest.once("end", res);
-							downloadRequest.once("error", rej);
-						}).finally(() => {
-							clearInterval(downloadInterval);
-							onDownloadProgress(downloadRequest.downloadProgress);
-						});
-
-						logger.log("Download complete!");
-						if (settings.extras.saveNfo) {
-							logger.log("Saving .nfo");
-							try {
-								await this.saveNfo();
-							} catch (error) {
-								// non-critical error
-								const message = this.parseErrorMessage(error);
-								logger.error(`Failed to save .nfo file! ${message} - Skipping`);
-							}
+		try {
+			if (settings.extras.saveNfo) {
+				this.logger.log("Saving .nfo");
+				await this.saveNfo().catch(withContext(`Saving .nfo file!`)).catch(this.onError);
+			}
+			if (settings.extras.downloadArtwork) {
+				this.logger.log("Saving artwork");
+				await this.downloadArtwork().catch(withContext(`Saving artwork!`)).catch(this.onError);
+			}
+			if ((await this.getState()) === Video.State.Muxed) return;
+			promQueued.inc();
+			for (let retries = 0; retries < Video.MaxRetries; retries++) {
+				try {
+					switch (await this.getState()) {
+						case Video.State.Missing: {
+							await this.onMissing().catch(withContext(`Downloading missing video!`));
 						}
-						if (settings.extras.downloadArtwork) {
-							logger.log("Saving artwork");
-							try {
-								await this.downloadArtwork();
-							} catch (error) {
-								// non-critical error
-								const message = this.parseErrorMessage(error);
-								logger.error(`Failed to save artwork! ${message} - Skipping`);
+						// eslint-disable-next-line no-fallthrough
+						case Video.State.Partial: {
+							this.logger.log("Muxing ffmpeg metadata...");
+							await this.muxffmpegMetadata().catch(withContext(`Muxing ffmpeg metadata`));
+
+							if (settings.postProcessingCommand !== "") {
+								this.logger.log(`Running settings.postProcessingCommand...`);
+								await this.postProcessingCommand().catch(withContext(`postProcessingCommand`));
 							}
-						}
-					}
-					// eslint-disable-next-line no-fallthrough
-					case Video.State.Partial: {
-						logger.log("Muxing ffmpeg metadata...");
-						await this.muxffmpegMetadata();
-
-						if (settings.postProcessingCommand !== "") {
-							logger.log(`Running post download command "${settings.postProcessingCommand}"...`);
-							await this.postProcessingCommand().catch((err) => logger.log(`postProcessingCommand failed! ${err.message}\n`));
-						}
 
-						if (settings.plex.enabled) {
-							await updatePlex().catch((err) => {
-								throw new Error(`Updating plex failed! ${err.message}`);
-							});
+							if (settings.plex.enabled) {
+								await updatePlex().catch(withContext(`Updating plex`));
+							}
 						}
 					}
-				}
-				logger.done(chalk`{cyan Download & Muxing complete!}`);
-				promDownloadedTotal.inc();
-				break;
-			} catch (error) {
-				const message = this.parseErrorMessage(error);
-				promErrors.labels({ message, attachmentId: this.attachmentId }).inc();
-
-				if (retries < Video.MaxRetries) {
-					logger.error(`${message} - Retrying in ${retries}s [${retries}/${Video.MaxRetries}]`);
-					await sleep(1000 * retries);
-				} else {
-					logger.error(`${message} - Failed`);
+					this.logger.done(chalk`{cyan Download & Muxing complete!}`);
+					promDownloadedTotal.inc();
+					break;
+				} catch (err: any) {
+					this.onError(err);
+					if (retries < Video.MaxRetries) await sleep(5000);
 				}
 			}
+		} finally {
+			await Video.DownloadSemaphore.release();
 		}
-		await Video.DownloadSemaphore.release();
 		promQueued.dec();
 	}
 
-	private parseErrorMessage(error: unknown): string {
-		let message = error instanceof Error ? error.message : `Something weird happened, whatever was thrown was not a error! ${error}`;
-		if (message.includes("ffmpeg")) {
-			const lastIndex = message.lastIndexOf(Video.Extensions.Partial);
-			if (lastIndex !== -1) {
-				message = `ffmpeg${message.substring(lastIndex + 9).replace(/\n|\r/g, "")}`;
-			}
-		}
-		return message;
+	private onError(err: any, throwAfterLog = false) {
+		const errStatement = this.logger.error(err);
+		console.error(`[${this.videoTitle}]`, errStatement);
+		promErrors.labels({ message: err?.message ?? err?.toString(), attachmentId: this.attachmentId }).inc();
+		if (throwAfterLog) throw err;
+	}
+
+	private async onMissing() {
+		this.logger.log("Waiting on delivery cdn...");
+		const downloadRequest = await this.getVideoStream(settings.floatplane.videoResolution);
+
+		// Pipe the download to the file once response starts
+		const writeStream = createWriteStream(this.partialPath);
+
+		// Throttle if enabled
+		if (Video.ThrottleGroup) {
+			// @ts-expect-error Type is wrong, this needs to be called with no arguments
+			const throttle = Video.ThrottleGroup.throttle();
+			downloadRequest.pipe(throttle).pipe(writeStream);
+		} else downloadRequest.pipe(writeStream);
+
+		let downloadedBytes = 0;
+		const onDownloadProgress = (progress: Progress) => {
+			const bytesSinceLast = progress.transferred - downloadedBytes;
+			downloadedBytes = progress.transferred;
+			promDownloadedBytes.inc(bytesSinceLast);
+			this.logger.onDownloadProgress(downloadRequest.downloadProgress, bytesSinceLast);
+		};
+
+		let downloadInterval: NodeJS.Timeout;
+		downloadRequest.once("downloadProgress", (downloadProgress: Progress) => {
+			this.logger.log("Download started!");
+			downloadInterval = setInterval(() => onDownloadProgress(downloadRequest.downloadProgress), 250);
+			onDownloadProgress(downloadProgress);
+		});
+
+		await new Promise((res, rej) => {
+			downloadRequest.once("end", res);
+			downloadRequest.once("error", rej);
+		}).finally(() => {
+			clearInterval(downloadInterval);
+			onDownloadProgress(downloadRequest.downloadProgress);
+		});
+
+		this.logger.log("Download complete!");
 	}
 
 	private static async pathBytes(path: string) {

diff --git a/src/lib/logging/ProgressBars.ts b/src/lib/logging/ProgressBars.ts
@@ -1,4 +1,4 @@
-import { MultiProgressBars } from "multi-progress-bars";
+import { MultiProgressBars, type UpdateOptions } from "multi-progress-bars";
 import { ProgressLogger, type IProgressLogger } from "./ProgressLogger.js";
 import type { Progress } from "got";
 import chalk from "chalk-template";
@@ -23,36 +23,36 @@ export class ProgressBars extends ProgressLogger implements IProgressLogger {
 		super(title);
 
 		this.title = title.slice(0, 32).trim();
+		let i = 1;
+		while (ProgressBars._Bars.getIndex(this.title) !== undefined) this.title = `${this.title} [${++i}]`;
 		ProgressBars.Total++;
 	}
-	private updateTask(...args: Parameters<typeof ProgressBars._Bars.updateTask>) {
+	private updateTask(updateOptions?: UpdateOptions) {
 		if (ProgressBars._Bars.getIndex(this.title) === undefined) {
 			ProgressBars._Bars.addTask(this.title, { type: "percentage" });
 		}
-		ProgressBars._Bars.updateTask(...args);
+		ProgressBars._Bars.updateTask(this.title, updateOptions);
 	}
 
-	public start() {
-		let i = 1;
-		while (ProgressBars._Bars.getIndex(this.title) !== undefined) this.title = `${this.title} [${++i}]`;
-		this.updateTask(this.title, { percentage: 0 });
-	}
 	public log(message: string) {
-		this.updateTask(this.title, { message });
+		this.updateTask({ message });
 	}
 	private reset() {
 		ProgressBars.DownloadSpeed -= this._downloadSpeed;
 		ProgressBars.DownloadSpeed = Math.abs(ProgressBars.DownloadSpeed);
 		this._downloadSpeed = 0;
 		this.updateSummaryBar();
 	}
-	public error(message: string) {
+	public error(err: any) {
 		ProgressBars.Errors++;
-		this.log(chalk`{red ERR}: ${message}`);
-		this.reset();
+		const errMsg = this.sanitizeError(err);
+		const errStatement = chalk`{red ERR}: ${errMsg}`;
+		this.log(errStatement);
+		return errStatement;
 	}
 	public done(message: string) {
 		ProgressBars.Done += 1;
+		this.updateTask(); // Ensure the bar exists
 		ProgressBars._Bars.done(this.title, { message });
 		this.reset();
 		setTimeout(() => ProgressBars._Bars.removeTask(this.title), 5000);
@@ -83,7 +83,7 @@ export class ProgressBars extends ProgressLogger implements IProgressLogger {
 		const speed = chalk`{green ${(this._downloadSpeed / 125000).toFixed(2)} mb/s}`;
 		const eta = chalk`ETA: {blue ${Math.floor(downloadETA / 60)}m ${Math.floor(downloadETA) % 60}s}`;
 
-		this.updateTask(this.title, {
+		this.updateTask({
 			percentage: progress.percent,
 			message: `${downloaded} ${speed} ${eta}`,
 		});

diff --git a/src/lib/logging/ProgressConsole.ts b/src/lib/logging/ProgressConsole.ts
@@ -4,8 +4,8 @@ export class ProgressHeadless extends ProgressLogger implements IProgressLogger
 	public log(message: string) {
 		console.log(`${this.title} - ${message}`);
 	}
-	public error(message: string) {
-		this.log(`An error occoured: ${message}`);
+	public error(err: any) {
+		this.log(`An error occoured: ${this.sanitizeError(err)}`);
 	}
 	public done = this.log;
 	public onDownloadProgress() {}

diff --git a/src/lib/logging/ProgressLogger.ts b/src/lib/logging/ProgressLogger.ts
@@ -3,7 +3,7 @@ import type { Progress } from "got";
 export interface IProgressLogger {
 	readonly title: string;
 	log(message: string): void;
-	error(message: string): void;
+	error(err: any, context: string): void;
 	onDownloadProgress(progress: Progress, bytesSinceLast: number): void;
 	done(message: string): void;
 }
@@ -13,4 +13,12 @@ export class ProgressLogger {
 	constructor(title: string) {
 		this.title = title.trim();
 	}
+	protected sanitizeError(err: any): string {
+		return err instanceof Error ? err.message : `Something weird happened, whatever was thrown was not a error! ${err}`;
+	}
 }
+
+export const withContext = (context: string) => (err: any) => {
+	if (err instanceof Error) throw new Error(`${context} - ${err.message}`);
+	throw err;
+};