Merge pull request #261 from Sofie-Automation/fix/connection-init-logging

Fix/connection init logging

Author: nytamin

apps/package-manager/packages/generic/src/packageManager.ts

@@ -145,7 +145,7 @@ export class PackageManagerHandler {
 
 		this.coreHandler.setPackageManagerHandler(this)
 
-		this.logger.info('PackageManagerHandler init')
+		this.logger.info('PackageManagerHandler init...')
 
 		coreHandler.onConnected(() => {
 			this.setupObservers()
@@ -157,10 +157,20 @@ export class PackageManagerHandler {
 		this.onSettingsChanged()
 		this.triggerUpdatedExpectedPackages()
 
-		await this.callbacksHandler.cleanReportedStatuses()
-		await this.expectationManager.init()
+		try {
+			await this.callbacksHandler.cleanReportedStatuses()
+		} catch (e) {
+			this.logger.error(`Error during cleanReportedStatuses()`)
+			throw e
+		}
+		try {
+			await this.expectationManager.init()
+		} catch (e) {
+			this.logger.error(`Error during expectationManager.init()`)
+			throw e
+		}
 
-		this.logger.info('PackageManagerHandler initialized')
+		this.logger.info('PackageManagerHandler initialized!')
 	}
 	onSettingsChanged(): void {
 		this.settings = {

shared/packages/api/src/websocketServer.ts

@@ -26,6 +26,10 @@ export class WebsocketServer extends HelpfulEventEmitter {
 
 		this.wss = new WebSocket.Server({ port: port })
 
+		this.wss.on('listening', () => {
+			this.logger.info(`Listening on port ${port}`)
+		})
+
 		this.wss.on('close', () => {
 			// The websocekt server is closed.
 

shared/packages/expectationManager/src/internalManager/lib/expectationManagerServer.ts

@@ -104,22 +104,22 @@ export class ExpectationManagerServer {
 				'*': 'ws://127.0.0.1',
 			}
 		}
-		this.logger.info(`##### type: ${this.workForceConnectionOptions.type}`)
+		this.logger.debug(`##### type: ${this.workForceConnectionOptions.type}`)
 		if (this.serverOptions.type === 'websocket' && this.serverOptions.port === 0) {
-			this.logger.info(`##### this.serverOptions.port: ${this.serverOptions.port}`)
+			this.logger.debug(`##### this.serverOptions.port: ${this.serverOptions.port}`)
 			// When the configured port i 0, the next free port is picked
 			for (const key of Object.keys(this._serverAccessUrls)) {
 				// If no port was specified in the url, add it:
 				if (!this._serverAccessUrls[key].match(/\/\/[^/]+:\d/)) {
-					this.logger.info(`updateing ${key}`)
+					this.logger.debug(`updateing ${key}`)
 					this._serverAccessUrls[key] += `:${this.manager.expectationManagerServer.websocketServer?.port}`
 				}
 			}
 		}
 
-		this.logger.info(`##### this.serverAccessBaseUrls: ${JSON.stringify(this.serverAccessBaseUrls)}`)
-		this.logger.info(`##### websocketServer?.port: ${this.manager.expectationManagerServer.websocketServer?.port}`)
-		this.logger.info(`##### this._serverAccessUrls: ${JSON.stringify(this._serverAccessUrls)}`)
+		this.logger.debug(`##### this.serverAccessBaseUrls: ${JSON.stringify(this.serverAccessBaseUrls)}`)
+		this.logger.debug(`##### websocketServer?.port: ${this.manager.expectationManagerServer.websocketServer?.port}`)
+		this.logger.debug(`##### this._serverAccessUrls: ${JSON.stringify(this._serverAccessUrls)}`)
 
 		if (!this._serverAccessUrls) throw new Error(`ExpectationManager.serverAccessUrl not set!`)
 	}

shared/packages/expectationManager/src/internalManager/lib/workforceConnection.ts

@@ -58,6 +58,9 @@ export class WorkforceConnection {
 		})
 	}
 	public async init(): Promise<void> {
+		if (this.workForceConnectionOptions.type === 'websocket') {
+			this.logger.info(`Connecting to Workforce at ${this.workForceConnectionOptions.url}`)
+		}
 		await this.workforceAPI.init(this.workForceConnectionOptions, {
 			setLogLevel: async (logLevel: LogLevel): Promise<void> => {
 				this.logger.setLogLevel(logLevel)

shared/packages/worker/src/workerAgent.ts

@@ -240,6 +240,9 @@ export class WorkerAgent {
 			const pAppContainer = new Promise<void>((resolve, reject) => {
 				this.initAppContainerAPIPromise = { resolve, reject }
 			})
+			if (this.appContainerConnectionOptions.type === 'websocket') {
+				this.logger.info(`Connecting to AppContainer at ${this.appContainerConnectionOptions.url}`)
+			}
 			await this.appContainerAPI.init(this.appContainerConnectionOptions, {
 				setLogLevel: async (logLevel: LogLevel) => this.setLogLevel(logLevel),
 				_debugKill: async () => this._debugKill(),
@@ -260,6 +263,9 @@ export class WorkerAgent {
 		const pWorkForce = new Promise<void>((resolve, reject) => {
 			this.initWorkForceAPIPromise = { resolve, reject }
 		})
+		if (this.workForceConnectionOptions.type === 'websocket') {
+			this.logger.info(`Connecting to Workforce at ${this.workForceConnectionOptions.url}`)
+		}
 		await this.workforceAPI.init(this.workForceConnectionOptions, {
 			setLogLevel: async (logLevel: LogLevel) => this.setLogLevel(logLevel),
 			_debugKill: async () => this._debugKill(),

shared/packages/workforce/src/workforce.ts

@@ -331,22 +331,21 @@ export class Workforce {
 	}
 
 	public async registerExpectationManager(managerId: ExpectationManagerId, urls: URLMap): Promise<void> {
-		let em = this.expectationManagers.get(managerId)
-		if (!em || deepEqual(em.urls, urls)) {
-			// Added/Changed
+		this.logger.info(`Register ExpectationManager (${managerId}) at URLs: ${JSON.stringify(urls)}`)
 
-			this.logger.info(`Workforce: Register ExpectationManager (${managerId}) at URLs: ${JSON.stringify(urls)}`)
-
-			// Announce the new expectation manager to the workerAgents:
-			for (const workerAgent of this.workerAgents.values()) {
-				await workerAgent.api.expectationManagerAvailable(managerId, urls)
-			}
-			em = this.expectationManagers.get(managerId)
-		}
+		const em = this.expectationManagers.get(managerId)
+		let hasChanged = false
 		if (!em) {
-			throw new Error(`Internal Error: (registerExpectationManager) ExpectationManager "${managerId}" not found!`)
+			hasChanged = true
+		} else if (!deepEqual(em.urls, urls)) {
+			em.urls = urls
+			hasChanged = true
+		}
+
+		if (hasChanged) {
+			// Announce the new/changed expectation manager to the workerAgents:
+			this.triggerAnnounceExpectationManagersToWorkers(managerId)
 		}
-		em.urls = urls
 	}
 	public async requestResourcesForExpectation(exp: Expectation.Any): Promise<boolean> {
 		return this.workerHandler.requestResourcesForExpectation(exp)
@@ -451,4 +450,42 @@ export class Workforce {
 				this.logger.error(`Workforce: Error in getRunningApps: ${stringifyError(error)}`)
 			})
 	}
+
+	private expectationManagersToAnnounceTimeout: NodeJS.Timeout | null = null
+	private triggerAnnounceExpectationManagersToWorkers(managerId: ExpectationManagerId): void {
+		this.expectationManagersToAnnounce.add(managerId)
+
+		if (this.expectationManagersToAnnounceTimeout) return // already scheduled to trigger
+
+		// Trigger an announce soon:
+		this.expectationManagersToAnnounceTimeout = setTimeout(() => {
+			this.expectationManagersToAnnounceTimeout = null
+
+			Promise.resolve()
+				.then(async () => {
+					await this._announceExpectationManagersToWorkers()
+				})
+				.catch((err) => {
+					this.logger.error(`Error in _triggerAnnounceExpectationManagersToWorkers: ${stringifyError(err)}`)
+				})
+		}, 1000)
+	}
+
+	private expectationManagersToAnnounce = new Set<ExpectationManagerId>()
+	private async _announceExpectationManagersToWorkers(): Promise<void> {
+		const managerIds = Array.from(this.expectationManagersToAnnounce.values())
+		this.expectationManagersToAnnounce.clear()
+
+		for (const managerId of managerIds) {
+			const em = this.expectationManagers.get(managerId)
+			if (em?.urls) {
+				const urls = em.urls
+				await Promise.all(
+					Array.from(this.workerAgents.values()).map(async (workerAgent) =>
+						workerAgent.api.expectationManagerAvailable(managerId, urls)
+					)
+				)
+			}
+		}
+	}
 }