Move SupervisorAPI state change logs to appropriate functions

Closes: #1277
Change-type: patch
Signed-off-by: Miguel Casqueira <miguel@balena.io>

src/supervisor-api.ts

@@ -82,6 +82,10 @@ interface SupervisorAPIConstructOpts {
 	healthchecks: Array<() => Promise<boolean>>;
 }
 
+interface SupervisorAPIStopOpts {
+	errored: boolean;
+}
+
 export class SupervisorAPI {
 	private config: Config;
 	private eventTracker: EventTracker;
@@ -200,8 +204,15 @@ export class SupervisorAPI {
 			}
 		});
 
-		this.server = this.api.listen(port);
-		this.server.timeout = apiTimeout;
+		return new Promise(resolve => {
+			this.server = this.api.listen(port, () => {
+				log.info(`Supervisor API successfully started on port ${port}`);
+				if (this.server) {
+					this.server.timeout = apiTimeout;
+				}
+				return resolve();
+			});
+		});
 	}
 
 	private async applyListeningRules(
@@ -218,17 +229,25 @@ export class SupervisorAPI {
 				log.debug('Supervisor API listening on allowed interfaces only');
 			}
 		} catch (err) {
-			log.error(
-				'Error on switching supervisor API listening rules - stopping API.\n',
-				err,
-			);
-			this.stop();
+			log.error('Error on switching supervisor API listening rules', err);
+			return this.stop({ errored: true });
 		}
 	}
 
-	public stop() {
+	public async stop(options?: SupervisorAPIStopOpts): Promise<void> {
 		if (this.server != null) {
-			this.server.close();
+			return new Promise((resolve, reject) => {
+				this.server?.close((err: Error) => {
+					if (err) {
+						log.error('Failed to stop Supervisor API');
+						return reject(err);
+					}
+					options?.errored
+						? log.error('Stopped Supervisor API')
+						: log.info('Stopped Supervisor API');
+					return resolve();
+				});
+			});
 		}
 	}
 }

test/21-supervisor-api.spec.ts

@@ -0,0 +1,110 @@
+import { expect } from 'chai';
+import { fs } from 'mz';
+import { spy } from 'sinon';
+
+import Config from '../src/config';
+import Database from '../src/db';
+import EventTracker from '../src/event-tracker';
+import Log from '../src/lib/supervisor-console';
+import SupervisorAPI from '../src/supervisor-api';
+
+const mockedOptions = {
+	listenPort: 12345,
+	timeout: 30000,
+	dbPath: './test/data/supervisor-api.sqlite',
+};
+
+const ALLOWED_INTERFACES = ['lo']; // Only need loopback since this is for testing
+
+describe('SupervisorAPI', () => {
+	describe('State change logging', () => {
+		let api: SupervisorAPI;
+		let db: Database;
+		let mockedConfig: Config;
+
+		before(async () => {
+			db = new Database({
+				databasePath: mockedOptions.dbPath,
+			});
+			await db.init();
+			mockedConfig = new Config({ db });
+			await mockedConfig.init();
+		});
+
+		beforeEach(async () => {
+			api = new SupervisorAPI({
+				config: mockedConfig,
+				eventTracker: new EventTracker(),
+				routers: [],
+				healthchecks: [],
+			});
+			spy(Log, 'info');
+			spy(Log, 'error');
+		});
+
+		afterEach(async () => {
+			// @ts-ignore
+			Log.info.restore();
+			// @ts-ignore
+			Log.error.restore();
+			try {
+				await api.stop();
+			} catch (e) {
+				if (e.message !== 'Server is not running.') {
+					// Ignore since server is already closed
+					throw e;
+				}
+			}
+		});
+
+		after(async () => {
+			try {
+				await fs.unlink(mockedOptions.dbPath);
+			} catch (e) {
+				/* noop */
+			}
+		});
+
+		it('logs successful start', async () => {
+			// Start API
+			await api.listen(
+				ALLOWED_INTERFACES,
+				mockedOptions.listenPort,
+				mockedOptions.timeout,
+			);
+			// Check if success start was logged
+			// @ts-ignore
+			expect(Log.info.lastCall?.lastArg).to.equal(
+				`Supervisor API successfully started on port ${mockedOptions.listenPort}`,
+			);
+		});
+
+		it('logs shutdown', async () => {
+			// Start API
+			await api.listen(
+				ALLOWED_INTERFACES,
+				mockedOptions.listenPort,
+				mockedOptions.timeout,
+			);
+			// Stop API
+			await api.stop();
+			// Check if stopped with info was logged
+			// @ts-ignore
+			expect(Log.info.lastCall?.lastArg).to.equal('Stopped Supervisor API');
+		});
+
+		it('logs errored shutdown', async () => {
+			// Start API
+			await api.listen(
+				ALLOWED_INTERFACES,
+				mockedOptions.listenPort,
+				mockedOptions.timeout,
+			);
+			// Stop API with error
+			await api.stop({ errored: true });
+			// Check if stopped with error was logged
+			// @ts-ignore
+			expect(Log.error.lastCall?.lastArg).to.equal('Stopped Supervisor API');
+		});
+	});
+});