chore: improve logging

nrkno · Sep 21, 2023 · 01fb101 · 01fb101
1 parent a50b1a2
commit 01fb101
Show file tree

Hide file tree

Showing 5 changed files with 22 additions and 11 deletions.
diff --git a/shared/packages/api/src/packageContainerApi.ts b/shared/packages/api/src/packageContainerApi.ts
@@ -28,7 +28,7 @@ export interface PackageContainerExpectation extends PackageContainer {
 			/** If set, ignore any files matching this. (Regular expression). */
 			ignore?: string
 
-			/** If set, the monitoring will be using polling */
+			/** If set, the monitoring will be using polling, at the given interval [ms] */
 			usePolling?: number | null
 			/** If set, will set the awaitWriteFinish.StabilityThreshold of chokidar */
 			awaitWriteFinishStabilityThreshold?: number | null

diff --git a/shared/packages/worker/src/worker/workers/windowsWorker/expectationHandlers/lib/scan.ts b/shared/packages/worker/src/worker/workers/windowsWorker/expectationHandlers/lib/scan.ts
@@ -1,5 +1,5 @@
 import { execFile, ChildProcess, spawn } from 'child_process'
-import { Expectation, assertNever, Accessor, AccessorOnPackage } from '@sofie-package-manager/api'
+import { Expectation, assertNever, Accessor, AccessorOnPackage, LoggerInstance } from '@sofie-package-manager/api'
 import {
 	isQuantelClipAccessorHandle,
 	isLocalFolderAccessorHandle,
@@ -227,7 +227,8 @@ export function scanMoreInfo(
 	onProgress: (
 		/** Progress, goes from 0 to 1 */
 		progress: number
-	) => void
+	) => void,
+	logger: LoggerInstance
 ): CancelablePromise<{
 	scenes: number[]
 	freezes: ScanAnomaly[]
@@ -310,7 +311,10 @@ export function scanMoreInfo(
 		ffMpegProcess.stderr.on('data', (data: any) => {
 			const stringData = data.toString()
 
-			if (typeof stringData !== 'string') return
+			if (typeof stringData !== 'string') {
+				logger.warn(`FFMpeg: bad stderr data (${typeof stringData})`)
+				return
+			}
 
 			try {
 				const frameRegex = /^frame= +\d+/g

diff --git a/...d/packages/worker/src/worker/workers/windowsWorker/expectationHandlers/packageDeepScan.ts b/...d/packages/worker/src/worker/workers/windowsWorker/expectationHandlers/packageDeepScan.ts
@@ -135,7 +135,7 @@ export const PackageDeepScan: ExpectationWindowsHandler = {
 		if (!lookupTarget.ready) throw new Error(`Can't start working due to target: ${lookupTarget.reason.tech}`)
 
 		let currentProcess: CancelablePromise<any> | undefined
-		const workInProgress = new WorkInProgress({ workLabel: 'Scanning file' }, async () => {
+		const workInProgress = new WorkInProgress({ workLabel: 'Deep Scanning file' }, async () => {
 			// On cancel
 			currentProcess?.cancel()
 		}).do(async () => {
@@ -184,9 +184,15 @@ export const PackageDeepScan: ExpectationWindowsHandler = {
 			let resultFreezes: ScanAnomaly[] = []
 			let resultScenes: number[] = []
 			if (hasVideoStream) {
-				currentProcess = scanMoreInfo(sourceHandle, ffProbeScan, exp.endRequirement.version, (progress) => {
-					workInProgress._reportProgress(sourceVersionHash, 0.21 + 0.77 * progress)
-				})
+				currentProcess = scanMoreInfo(
+					sourceHandle,
+					ffProbeScan,
+					exp.endRequirement.version,
+					(progress) => {
+						workInProgress._reportProgress(sourceVersionHash, 0.21 + 0.77 * progress)
+					},
+					worker.logger.category('scanMoreInfo')
+				)
 				const result = await currentProcess
 				resultBlacks = result.blacks
 				resultFreezes = result.freezes

diff --git a/...ckages/worker/src/worker/workers/windowsWorker/expectationHandlers/packageLoudnessScan.ts b/...ckages/worker/src/worker/workers/windowsWorker/expectationHandlers/packageLoudnessScan.ts
@@ -134,7 +134,7 @@ export const PackageLoudnessScan: ExpectationWindowsHandler = {
 		if (!lookupTarget.ready) throw new Error(`Can't start working due to target: ${lookupTarget.reason.tech}`)
 
 		let currentProcess: CancelablePromise<any> | undefined
-		const workInProgress = new WorkInProgress({ workLabel: 'Scanning file' }, async () => {
+		const workInProgress = new WorkInProgress({ workLabel: 'Scanning file (loudness)' }, async () => {
 			// On cancel
 			currentProcess?.cancel()
 		}).do(async () => {

diff --git a/shared/packages/worker/src/workerAgent.ts b/shared/packages/worker/src/workerAgent.ts
@@ -447,13 +447,14 @@ export class WorkerAgent {
 							currentJob.timeoutInterval = null
 							return
 						}
+						const timeSinceLastUpdate = Date.now() - currentJob.lastUpdated
 
-						if (Date.now() - currentJob.lastUpdated > timeout) {
+						if (timeSinceLastUpdate > timeout) {
 							// The job seems to have timed out.
 							// Expectation Manager will clean up on it's side, we have to do the same here.
 
 							this.logger.warn(
-								`WorkerAgent: Cancelling job "${currentJob.workInProgress?.properties.workLabel}" (${currentJob.wipId}) due to timeout (${timeout})`
+								`WorkerAgent: Cancelling job "${currentJob.workInProgress?.properties.workLabel}" (${currentJob.wipId}) due to timeout (${timeSinceLastUpdate} > ${timeout})`
 							)
 							if (currentJob.timeoutInterval) {
 								clearInterval(currentJob.timeoutInterval)