From bad15dff0ec08e7b3873b961ff387bec5d1f2318 Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 23 Jan 2025 09:34:56 +0100 Subject: [PATCH 1/4] fix: An issue where expectations that are fulfilled but waiting on other expectation, loop through fullfilled->new->waiting->fullfilled statuses. This was caused by the WAITING state didn't check if the expectaiton was waiting for another BEFORE checking if it was fulfilled. But the FULFILLED state did. --- shared/packages/api/src/worker.ts | 1 - .../evaluateExpectationStates/waiting.ts | 89 ++++++++++--------- .../lib/trackedExpectationAPI.ts | 14 --- 3 files changed, 48 insertions(+), 56 deletions(-) diff --git a/shared/packages/api/src/worker.ts b/shared/packages/api/src/worker.ts index 31d392ac..17ffe2ef 100644 --- a/shared/packages/api/src/worker.ts +++ b/shared/packages/api/src/worker.ts @@ -31,7 +31,6 @@ export type ReturnTypeIsExpectationReadyToStartWorkingOn = */ sourceExists?: boolean isPlaceholder?: boolean - isWaitingForAnother?: boolean reason: Reason } export type ReturnTypeIsExpectationFulfilled = diff --git a/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/waiting.ts b/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/waiting.ts index 20b0bda5..f6ca474e 100644 --- a/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/waiting.ts +++ b/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/waiting.ts @@ -23,6 +23,22 @@ export async function evaluateExpectationStateWaiting({ if (trackedExp.session.assignedWorker) { try { + // First check if the Expectation depends on the fulfilled-status of another Expectation: + const isWaitingForOther = tracker.trackedExpectationAPI.isExpectationWaitingForOther(trackedExp) + + if (isWaitingForOther) { + // Not ready to start because it's waiting for another expectation to be fulfilled first + // Stay here in WAITING state: + tracker.trackedExpectationAPI.updateTrackedExpectationStatus(trackedExp, { + reason: { + user: `Waiting for "${isWaitingForOther.exp.statusReport.label}"`, + tech: `Waiting for "${isWaitingForOther.exp.statusReport.label}"`, + }, + }) + + return + } + // First, check if it is already fulfilled: const fulfilled = await trackedExp.session.assignedWorker.worker.isExpectationFulfilled( trackedExp.exp, @@ -30,6 +46,7 @@ export async function evaluateExpectationStateWaiting({ ) if (fulfilled.fulfilled) { // The expectation is already fulfilled: + tracker.trackedExpectationAPI.updateTrackedExpectationStatus(trackedExp, { state: ExpectedPackageStatusAPI.WorkStatusState.FULFILLED, }) @@ -37,49 +54,39 @@ export async function evaluateExpectationStateWaiting({ // Something was triggered, run again ASAP: trackedExp.session.triggerOtherExpectationsAgain = true } - } else { - const readyToStart = await tracker.trackedExpectationAPI.isExpectationReadyToStartWorkingOn( - trackedExp.session.assignedWorker.worker, - trackedExp - ) + return + } + const readyToStart = await tracker.trackedExpectationAPI.isExpectationReadyToStartWorkingOn( + trackedExp.session.assignedWorker.worker, + trackedExp + ) - const newStatus: Partial = {} - { - const sourceExists = readyToStart.ready || readyToStart.sourceExists - if (sourceExists !== undefined) newStatus.sourceExists = sourceExists - } - { - const isPlaceholder = readyToStart.ready ? false : readyToStart.isPlaceholder - if (isPlaceholder !== undefined) newStatus.sourceIsPlaceholder = isPlaceholder - } + const newStatus: Partial = {} + { + const sourceExists = readyToStart.ready || readyToStart.sourceExists + if (sourceExists !== undefined) newStatus.sourceExists = sourceExists + } + { + const isPlaceholder = readyToStart.ready ? false : readyToStart.isPlaceholder + if (isPlaceholder !== undefined) newStatus.sourceIsPlaceholder = isPlaceholder + } - if (readyToStart.ready) { - tracker.trackedExpectationAPI.updateTrackedExpectationStatus(trackedExp, { - state: ExpectedPackageStatusAPI.WorkStatusState.READY, - reason: { - user: 'About to start working..', - tech: `About to start, was not fulfilled: ${fulfilled.reason.tech}`, - }, - status: newStatus, - }) - } else { - // Not ready to start - if (readyToStart.isWaitingForAnother) { - // Not ready to start because it's waiting for another expectation to be fulfilled first - // Stay here in WAITING state: - tracker.trackedExpectationAPI.updateTrackedExpectationStatus(trackedExp, { - reason: readyToStart.reason, - status: newStatus, - }) - } else { - // Not ready to start because of some other reason (e.g. the source doesn't exist) - // Stay here in WAITING state: - tracker.trackedExpectationAPI.updateTrackedExpectationStatus(trackedExp, { - reason: readyToStart.reason, - status: newStatus, - }) - } - } + if (readyToStart.ready) { + tracker.trackedExpectationAPI.updateTrackedExpectationStatus(trackedExp, { + state: ExpectedPackageStatusAPI.WorkStatusState.READY, + reason: { + user: 'About to start working..', + tech: `About to start, was not fulfilled: ${fulfilled.reason.tech}`, + }, + status: newStatus, + }) + } else { + // Not ready to start because of some reason (e.g. the source doesn't exist) + // Stay here in WAITING state: + tracker.trackedExpectationAPI.updateTrackedExpectationStatus(trackedExp, { + reason: readyToStart.reason, + status: newStatus, + }) } } catch (error) { // There was an error, clearly it's not ready to start diff --git a/shared/packages/expectationManager/src/expectationTracker/lib/trackedExpectationAPI.ts b/shared/packages/expectationManager/src/expectationTracker/lib/trackedExpectationAPI.ts index da0cb1a4..9c627bcd 100644 --- a/shared/packages/expectationManager/src/expectationTracker/lib/trackedExpectationAPI.ts +++ b/shared/packages/expectationManager/src/expectationTracker/lib/trackedExpectationAPI.ts @@ -110,20 +110,6 @@ export class TrackedExpectationAPI { workerAgent: WorkerAgentAPI, trackedExp: TrackedExpectation ): Promise { - // First check if the Expectation depends on the fulfilled-status of another Expectation: - const waitingFor = this.isExpectationWaitingForOther(trackedExp) - - if (waitingFor) { - return { - ready: false, - reason: { - user: `Waiting for "${waitingFor.exp.statusReport.label}"`, - tech: `Waiting for "${waitingFor.exp.statusReport.label}"`, - }, - isWaitingForAnother: true, - } - } - return workerAgent.isExpectationReadyToStartWorkingOn(trackedExp.exp) } /** Checks if the expectation is waiting for another expectation, and returns the awaited Expectation, otherwise null */ From 4c244b12713c3b3011e105e10c623424a41e2a9d Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 23 Jan 2025 09:51:20 +0100 Subject: [PATCH 2/4] fix: Check that Quantel source clips exist earlier, to avoid crashing out of a WorkInProgress. --- .../src/worker/accessorHandlers/quantel.ts | 19 ++++++++++++++++++- 1 file changed, 18 insertions(+), 1 deletion(-) diff --git a/shared/packages/worker/src/worker/accessorHandlers/quantel.ts b/shared/packages/worker/src/worker/accessorHandlers/quantel.ts index 4e6cb664..9c0f0c26 100644 --- a/shared/packages/worker/src/worker/accessorHandlers/quantel.ts +++ b/shared/packages/worker/src/worker/accessorHandlers/quantel.ts @@ -155,8 +155,9 @@ export class QuantelAccessorHandle extends GenericAccessorHandle extends GenericAccessorHandle extends GenericAccessorHandle Date: Thu, 23 Jan 2025 10:07:32 +0100 Subject: [PATCH 3/4] fix: log reason why no worker can handle expectation --- .../packages/generic/src/appContainer.ts | 14 ++++++++++++-- 1 file changed, 12 insertions(+), 2 deletions(-) diff --git a/apps/appcontainer-node/packages/generic/src/appContainer.ts b/apps/appcontainer-node/packages/generic/src/appContainer.ts index 05e22d7c..de35a152 100644 --- a/apps/appcontainer-node/packages/generic/src/appContainer.ts +++ b/apps/appcontainer-node/packages/generic/src/appContainer.ts @@ -40,6 +40,7 @@ import { import { WorkforceAPI } from './workforceApi' import { WorkerAgentAPI } from './workerAgentApi' +import { ExpectedPackageStatusAPI } from '@sofie-automation/shared-lib/dist/package-manager/package' /** Mimimum time between app restarts */ const RESTART_COOLDOWN = 60 * 1000 // ms @@ -413,6 +414,10 @@ export class AppContainer { this.logger.debug(`Available apps: ${Array.from(this.availableApps.keys()).join(', ')}`) } + let lastNotSupportReason: ExpectedPackageStatusAPI.Reason = { + user: 'No apps available', + tech: 'No apps available', + } for (const [appType, availableApp] of this.availableApps.entries()) { const runningApp = await this.getRunningOrSpawnScalingApp(appType) @@ -424,6 +429,11 @@ export class AppContainer { appType: appType, cost: availableApp.cost, } + } else { + lastNotSupportReason = result.reason + this.logger.silly( + `App "${appType}": Does not support the expectation, reason: "${result.reason.tech}", cost: "${availableApp.cost}"` + ) } } else { this.logger.warn(`appType "${appType}" not available`) @@ -432,8 +442,8 @@ export class AppContainer { return { success: false, reason: { - user: `No worker supports this expectation`, - tech: `No worker supports this expectation`, + user: `No worker supports this expectation (reason: ${lastNotSupportReason?.user})`, + tech: `No worker supports this expectation (one reason: ${lastNotSupportReason?.tech})`, }, } } From 7a61f5f253e73a9e86309f49db802e8b182cfd31 Mon Sep 17 00:00:00 2001 From: Johan Nyman Date: Thu, 23 Jan 2025 10:52:04 +0100 Subject: [PATCH 4/4] chore: doc & prepare-tests script --- scripts/prepare-for-tests.mjs | 10 ++++++++++ .../evaluateExpectationStates/fulfilled.ts | 1 + 2 files changed, 11 insertions(+) diff --git a/scripts/prepare-for-tests.mjs b/scripts/prepare-for-tests.mjs index c93ea593..30ac72a0 100644 --- a/scripts/prepare-for-tests.mjs +++ b/scripts/prepare-for-tests.mjs @@ -13,6 +13,8 @@ import path from 'path' import cp from 'child_process' import fetch from 'node-fetch' +console.log(`Preparing for tests...`) + const targetVersions = JSON.parse(await fs.readFile('./tests/ffmpegReleases.json')) const toPosix = (str) => str.split(path.sep).join(path.posix.sep) @@ -33,12 +35,14 @@ async function pathExists(path) { const platformInfo = `${process.platform}-${process.arch}` const platformVersions = targetVersions[platformInfo] +let didDoAnything = false if (platformVersions) { for (const version of platformVersions) { const versionPath = path.join(ffmpegRootDir, version.id) const dirStat = await pathExists(versionPath) if (!dirStat) { + didDoAnything = true console.log(`Fetching ${version.url}`) // Download it @@ -81,3 +85,9 @@ if (platformVersions) { } else { throw new Error(`No FFMpeg binaries have been defined for "${platformInfo}" yet`) } + +if (!didDoAnything) { + console.log(`Nothing to prepare!`) +} else { + console.log(`Preparations done!`) +} diff --git a/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/fulfilled.ts b/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/fulfilled.ts index 44ab3126..84b593b8 100644 --- a/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/fulfilled.ts +++ b/shared/packages/expectationManager/src/evaluationRunner/evaluateExpectationStates/fulfilled.ts @@ -19,6 +19,7 @@ export async function evaluateExpectationStateFulfilled({ assertState(trackedExp, ExpectedPackageStatusAPI.WorkStatusState.FULFILLED) // TODO: Some monitor that is able to invalidate if it isn't fulfilled anymore? + // We don't want to check too often if it's still fulfilled: if (timeSinceLastEvaluation > tracker.getFulfilledWaitTime()) { await manager.workerAgents.assignWorkerToSession(trackedExp) if (trackedExp.session.assignedWorker) {