Merge branch 'release51'

meteor/CHANGELOG.md

@@ -2,6 +2,22 @@
 
 All notable changes to this project will be documented in this file. See [standard-version](https://github.com/conventional-changelog/standard-version) for commit guidelines.
 
+### [1.51.6](///compare/v1.51.5...v1.51.6) (2025-01-14)
+
+
+### Features
+
+* add more logging 8c16ce8
+
+
+### Bug Fixes
+
+* Include previousPartInstance in check to orphan segments rather than remove them. 51b7104
+* only run onPart/PiecePlaybackStarted/Stopped on current, next or previous parts a9fe401
+* **PoGw:** filter log output to ensure that message field in JSONL output is never an object 0d2b844
+* set nextPartInstance to null if it's referring to a Segment that has been removed b1045f9
+* updatePartInstancesSegmentIds: take into account when multiple segments have been merged into one. b769157
+
 ### [1.51.5](///compare/v1.51.4...v1.51.5) (2025-01-07)
 
 

meteor/package.json

@@ -1,6 +1,6 @@
 {
 	"name": "automation-core",
-	"version": "1.51.5",
+	"version": "1.51.6",
 	"private": true,
 	"engines": {
 		"node": ">=14.19.1"

meteor/yarn.lock

@@ -1321,7 +1321,7 @@ __metadata:
   version: 0.0.0-use.local
   resolution: "@sofie-automation/blueprints-integration@portal:../packages/blueprints-integration::locator=automation-core%40workspace%3A."
   dependencies:
-    "@sofie-automation/shared-lib": 1.51.5
+    "@sofie-automation/shared-lib": 1.51.6
     tslib: ^2.6.2
     type-fest: ^3.13.1
   languageName: node
@@ -1362,8 +1362,8 @@ __metadata:
   version: 0.0.0-use.local
   resolution: "@sofie-automation/corelib@portal:../packages/corelib::locator=automation-core%40workspace%3A."
   dependencies:
-    "@sofie-automation/blueprints-integration": 1.51.5
-    "@sofie-automation/shared-lib": 1.51.5
+    "@sofie-automation/blueprints-integration": 1.51.6
+    "@sofie-automation/shared-lib": 1.51.6
     fast-clone: ^1.5.13
     i18next: ^21.10.0
     influx: ^5.9.3
@@ -1394,9 +1394,9 @@ __metadata:
   resolution: "@sofie-automation/job-worker@portal:../packages/job-worker::locator=automation-core%40workspace%3A."
   dependencies:
     "@slack/webhook": ^6.1.0
-    "@sofie-automation/blueprints-integration": 1.51.5
-    "@sofie-automation/corelib": 1.51.5
-    "@sofie-automation/shared-lib": 1.51.5
+    "@sofie-automation/blueprints-integration": 1.51.6
+    "@sofie-automation/corelib": 1.51.6
+    "@sofie-automation/shared-lib": 1.51.6
     amqplib: ^0.10.3
     deepmerge: ^4.3.1
     elastic-apm-node: ^3.51.0

packages/blueprints-integration/CHANGELOG.md

@@ -3,6 +3,14 @@
 All notable changes to this project will be documented in this file.
 See [Conventional Commits](https://conventionalcommits.org) for commit guidelines.
 
+## [1.51.6](https://github.com/nrkno/sofie-core/compare/v1.51.5...v1.51.6) (2025-01-14)
+
+**Note:** Version bump only for package @sofie-automation/blueprints-integration
+
+
+
+
+
 ## [1.51.5](https://github.com/nrkno/sofie-core/compare/v1.51.4...v1.51.5) (2025-01-07)
 
 **Note:** Version bump only for package @sofie-automation/blueprints-integration

packages/blueprints-integration/package.json

@@ -1,6 +1,6 @@
 {
 	"name": "@sofie-automation/blueprints-integration",
-	"version": "1.51.5",
+	"version": "1.51.6",
 	"description": "Library to define the interaction between core and the blueprints.",
 	"main": "dist/index.js",
 	"typings": "dist/index.d.ts",
@@ -38,7 +38,7 @@
 		"/LICENSE"
 	],
 	"dependencies": {
-		"@sofie-automation/shared-lib": "1.51.5",
+		"@sofie-automation/shared-lib": "1.51.6",
 		"tslib": "^2.6.2",
 		"type-fest": "^3.13.1"
 	},

packages/corelib/package.json

@@ -1,6 +1,6 @@
 {
 	"name": "@sofie-automation/corelib",
-	"version": "1.51.5",
+	"version": "1.51.6",
 	"private": true,
 	"description": "Internal library for some types shared by core and workers",
 	"main": "dist/index.js",
@@ -39,8 +39,8 @@
 		"/LICENSE"
 	],
 	"dependencies": {
-		"@sofie-automation/blueprints-integration": "1.51.5",
-		"@sofie-automation/shared-lib": "1.51.5",
+		"@sofie-automation/blueprints-integration": "1.51.6",
+		"@sofie-automation/shared-lib": "1.51.6",
 		"fast-clone": "^1.5.13",
 		"i18next": "^21.10.0",
 		"influx": "^5.9.3",

packages/documentation/package.json

@@ -1,6 +1,6 @@
 {
 	"name": "sofie-documentation",
-	"version": "1.51.5",
+	"version": "1.51.6",
 	"private": true,
 	"scripts": {
 		"docusaurus": "docusaurus",

packages/job-worker/package.json

@@ -1,6 +1,6 @@
 {
 	"name": "@sofie-automation/job-worker",
-	"version": "1.51.5",
+	"version": "1.51.6",
 	"description": "Worker for things",
 	"main": "dist/index.js",
 	"license": "MIT",
@@ -41,9 +41,9 @@
 	],
 	"dependencies": {
 		"@slack/webhook": "^6.1.0",
-		"@sofie-automation/blueprints-integration": "1.51.5",
-		"@sofie-automation/corelib": "1.51.5",
-		"@sofie-automation/shared-lib": "1.51.5",
+		"@sofie-automation/blueprints-integration": "1.51.6",
+		"@sofie-automation/corelib": "1.51.6",
+		"@sofie-automation/shared-lib": "1.51.6",
 		"amqplib": "^0.10.3",
 		"deepmerge": "^4.3.1",
 		"elastic-apm-node": "^3.51.0",

packages/job-worker/src/ingest/commit.ts

@@ -178,9 +178,13 @@ export async function CommitIngestOperation(
 			// Ensure any adlibbed parts are updated to follow the segmentId of the previous part
 			await updateSegmentIdsForAdlibbedPartInstances(context, ingestModel, beforePartMap)
 
+			// TODO: This whole section can probably be removed later, it's really unneccessary in the grand scheme of
+			// things, it's here only to debug some problems
 			if (data.renamedSegments && data.renamedSegments.size > 0) {
-				logger.debug(`Renamed segments: ${JSON.stringify(Array.from(data.renamedSegments.entries()))}`)
+				logger.verbose(`Renamed segments: ${JSON.stringify(Array.from(data.renamedSegments.entries()))}`)
 			}
+			// End of temporary section
+
 			// ensure instances have matching segmentIds with the parts
 			await updatePartInstancesSegmentIds(context, ingestModel, data.renamedSegments, beforePartMap)
 
@@ -220,6 +224,8 @@ export async function CommitIngestOperation(
 			const pSaveIngest = ingestModel.saveAllToDatabase()
 			pSaveIngest.catch(() => null) // Ensure promise isn't reported as unhandled
 
+			ensureNextPartInstanceIsNotDeleted(playoutModel)
+
 			await validateAdlibTestingSegment(context, playoutModel)
 
 			try {
@@ -273,14 +279,18 @@ function canRemoveSegment(
 		logger.warn(`Not allowing removal of previous playing segment "${segmentId}", making segment unsynced instead`)
 		return false
 	}
-	if (
-		currentPartInstance?.segmentId === segmentId ||
-		(nextPartInstance?.segmentId === segmentId && isTooCloseToAutonext(currentPartInstance, false))
-	) {
+	if (currentPartInstance?.segmentId === segmentId) {
 		// Don't allow removing an active rundown
 		logger.warn(`Not allowing removal of current playing segment "${segmentId}", making segment unsynced instead`)
 		return false
 	}
+	if (nextPartInstance?.segmentId === segmentId && isTooCloseToAutonext(currentPartInstance, false)) {
+		// Don't allow removing an active rundown
+		logger.warn(
+			`Not allowing removal of nexted segment "${segmentId}", because it's too close to an auto-next, making segment unsynced instead`
+		)
+		return false
+	}
 
 	if (nextPartInstance?.segmentId === segmentId && nextPartInstance.orphaned === 'adlib-part') {
 		// Don't allow removing an active rundown
@@ -365,6 +375,8 @@ async function updatePartInstancesSegmentIds(
 
 		const writeOps: AnyBulkWriteOperation<DBPartInstance>[] = []
 
+		logger.debug(`updatePartInstancesSegmentIds: renameRules: ${JSON.stringify(renameRules)}`)
+
 		for (const [newSegmentId, rule] of rulesInOrder) {
 			if (rule.fromSegmentIds.length) {
 				writeOps.push({
@@ -402,32 +414,24 @@ async function updatePartInstancesSegmentIds(
 		if (writeOps.length) await context.directCollections.PartInstances.bulkWrite(writeOps)
 
 		// Double check that there are no parts using the old segment ids:
-		const oldSegmentIds = Array.from(renameRules.keys())
-		const [badPartInstances, badParts] = await Promise.all([
-			await context.directCollections.PartInstances.findFetch({
-				rundownId: ingestModel.rundownId,
-				segmentId: { $in: oldSegmentIds },
-			}),
-			await context.directCollections.Parts.findFetch({
-				rundownId: ingestModel.rundownId,
-				segmentId: { $in: oldSegmentIds },
-			}),
-		])
+		// TODO: This whole section can probably be removed later, it's really unneccessary in the grand scheme of
+		// things, it's here only to debug some problems
+		const oldSegmentIds: SegmentId[] = []
+		for (const renameRule of renameRules.values()) {
+			oldSegmentIds.push(...renameRule.fromSegmentIds)
+		}
+		const badPartInstances = await context.directCollections.PartInstances.findFetch({
+			rundownId: ingestModel.rundownId,
+			segmentId: { $in: oldSegmentIds },
+		})
 		if (badPartInstances.length > 0) {
 			logger.error(
 				`updatePartInstancesSegmentIds: Failed to update all PartInstances using old SegmentIds "${JSON.stringify(
 					oldSegmentIds
 				)}": ${JSON.stringify(badPartInstances)}, writeOps: ${JSON.stringify(writeOps)}`
 			)
 		}
-
-		if (badParts.length > 0) {
-			logger.error(
-				`updatePartInstancesSegmentIds: Failed to update all Parts using old SegmentIds "${JSON.stringify(
-					oldSegmentIds
-				)}": ${JSON.stringify(badParts)}, writeOps: ${JSON.stringify(writeOps)}`
-			)
-		}
+		// End of the temporary section
 	}
 }
 
@@ -662,10 +666,27 @@ async function getSelectedPartInstances(
 			  })
 			: []
 
+	const currentPartInstance = instances.find((inst) => inst._id === playlist.currentPartInfo?.partInstanceId)
+	const nextPartInstance = instances.find((inst) => inst._id === playlist.nextPartInfo?.partInstanceId)
+	const previousPartInstance = instances.find((inst) => inst._id === playlist.previousPartInfo?.partInstanceId)
+
+	if (playlist.currentPartInfo?.partInstanceId && !currentPartInstance)
+		logger.error(
+			`playlist.currentPartInfo is set, but PartInstance "${playlist.currentPartInfo?.partInstanceId}" was not found!`
+		)
+	if (playlist.nextPartInfo?.partInstanceId && !nextPartInstance)
+		logger.error(
+			`playlist.nextPartInfo is set, but PartInstance "${playlist.nextPartInfo?.partInstanceId}" was not found!`
+		)
+	if (playlist.previousPartInfo?.partInstanceId && !previousPartInstance)
+		logger.error(
+			`playlist.previousPartInfo is set, but PartInstance "${playlist.previousPartInfo?.partInstanceId}" was not found!`
+		)
+
 	return {
-		currentPartInstance: instances.find((inst) => inst._id === playlist.currentPartInfo?.partInstanceId),
-		nextPartInstance: instances.find((inst) => inst._id === playlist.nextPartInfo?.partInstanceId),
-		previousPartInstance: instances.find((inst) => inst._id === playlist.previousPartInfo?.partInstanceId),
+		currentPartInstance,
+		nextPartInstance,
+		previousPartInstance,
 	}
 }
 
@@ -815,6 +836,16 @@ async function removeSegments(
 		})
 	}
 	for (const segmentId of purgeSegmentIds) {
+		logger.debug(
+			`IngestModel: Removing segment "${segmentId}" (` +
+				`previousPartInfo?.partInstanceId: ${newPlaylist.previousPartInfo?.partInstanceId},` +
+				`currentPartInfo?.partInstanceId: ${newPlaylist.currentPartInfo?.partInstanceId},` +
+				`nextPartInfo?.partInstanceId: ${newPlaylist.nextPartInfo?.partInstanceId},` +
+				`previousPartInstance.segmentId: ${!previousPartInstance ? 'N/A' : previousPartInstance.segmentId},` +
+				`currentPartInstance.segmentId: ${!currentPartInstance ? 'N/A' : currentPartInstance.segmentId},` +
+				`nextPartInstance.segmentId: ${!nextPartInstance ? 'N/A' : nextPartInstance.segmentId}` +
+				`)`
+		)
 		ingestModel.removeSegment(segmentId)
 	}
 }
@@ -824,3 +855,12 @@ async function validateAdlibTestingSegment(_context: JobContext, playoutModel: P
 		rundown.updateAdlibTestingSegmentRank()
 	}
 }
+function ensureNextPartInstanceIsNotDeleted(playoutModel: PlayoutModel) {
+	if (playoutModel.nextPartInstance) {
+		// Check if the segment of the nextPartInstance exists
+		if (!playoutModel.findSegment(playoutModel.nextPartInstance.partInstance.segmentId)) {
+			// The segment doesn't exist, set nextPartInstance to null, it'll be set by ensureNextPartIsValid() later.
+			playoutModel.setPartInstanceAsNext(null, false, false)
+		}
+	}
+}

packages/job-worker/src/ingest/lock.ts

@@ -22,8 +22,11 @@ export interface CommitIngestData {
 	removedSegmentIds: SegmentId[]
 	/**
 	 * Segments that had their ids changed. This helps then be orphaned in the correct place
-	 * eg, whole segment is renamed and middle part deleted
-	 * Note: Only supported for MOS, not 'normal' ingest operations
+	 * eg, whole segment is renamed and middle part deleted.
+	 *
+	 * Maps fromSegmentId to toSegmentId.
+	 *
+	 * _Note: Only supported for MOS, not 'normal' ingest operations_
 	 */
 	renamedSegments: Map<SegmentId, SegmentId> | null
 

packages/job-worker/src/ingest/mosDevice/diff.ts

@@ -11,6 +11,7 @@ import { IngestSegment } from '@sofie-automation/blueprints-integration'
 import { SegmentOrphanedReason } from '@sofie-automation/corelib/dist/dataModel/Segment'
 import { CommitIngestData } from '../lock'
 import { IngestSegmentModel } from '../model/IngestSegmentModel'
+import { logger } from '../../logging'
 
 /**
  * Update the Ids of Segments based on new Ingest data
@@ -158,9 +159,11 @@ function applyExternalIdDiff(
 			}
 
 			// Remove the old Segment and it's contents, the new one will be generated shortly
+			logger.debug(`applyExternalIdDiff: Marking Segment for removing "${oldSegmentId}"`)
 			ingestModel.removeSegment(oldSegmentId)
 		} else {
 			// Perform the rename
+			logger.debug(`applyExternalIdDiff: Marking Segment for renaming "${oldSegmentId}" -> "${newSegmentId}"`)
 			ingestModel.changeSegmentId(oldSegmentId, newSegmentId)
 		}
 	}

packages/job-worker/src/ingest/syncChangesToPartInstance.ts

@@ -33,6 +33,7 @@ import { validateAdlibTestingPartInstanceProperties } from '../playout/adlibTest
 import { ReadonlyDeep } from 'type-fest'
 import { convertIngestModelToPlayoutRundownWithSegments } from './commit'
 import { PlayoutRundownModel } from '../playout/model/PlayoutRundownModel'
+import { PieceInstance } from '@sofie-automation/corelib/dist/dataModel/PieceInstance'
 
 type PlayStatus = 'previous' | 'current' | 'next'
 type SyncedInstance = {
@@ -143,15 +144,29 @@ export async function syncChangesToPartInstances(
 				if (!playoutRundownModelForPart)
 					throw new Error(`Internal Error: playoutRundownModelForPart is undefined (it should never be)`)
 
-				const proposedPieceInstances = getPieceInstancesForPart(
-					context,
-					playoutModel,
-					previousPartInstance,
-					playoutRundownModelForPart,
-					part,
-					await piecesThatMayBeActive,
-					existingPartInstance.partInstance._id
-				)
+				// TMP: wrap in try/catch for troubleshooting:
+				let proposedPieceInstances: PieceInstance[] = []
+				try {
+					proposedPieceInstances = getPieceInstancesForPart(
+						context,
+						playoutModel,
+						previousPartInstance,
+						playoutRundownModelForPart,
+						part,
+						await piecesThatMayBeActive,
+						existingPartInstance.partInstance._id
+					)
+				} catch (e) {
+					logger.error(
+						`TROUBLESHOOTING: currentPartInstance: ${JSON.stringify(playoutModel.currentPartInstance)}`
+					)
+					logger.error(`TROUBLESHOOTING: nextPartInstance: ${JSON.stringify(playoutModel.nextPartInstance)}`)
+					logger.error(
+						`TROUBLESHOOTING: previousPartInstance: ${JSON.stringify(playoutModel.previousPartInstance)}`
+					)
+
+					throw e
+				}
 
 				logger.info(`Syncing ingest changes for part: ${partId} (orphaned: ${!!newPart})`)
 

packages/job-worker/src/playout/adlibJobs.ts

@@ -438,6 +438,7 @@ export async function handleDisableNextPiece(context: JobContext, data: DisableN
 
 				return sortedPieces.find((piece) => {
 					return (
+						piece.pieceInstance.piece.enable.start !== 'now' &&
 						piece.pieceInstance.piece.enable.start >= nowInPart &&
 						((!data.undo && !piece.pieceInstance.disabled) || (data.undo && piece.pieceInstance.disabled))
 					)