Clean up local mode engine objects using snapshots

Snapshot is collected to compare with engine state when local mode is turned off.

Change-type: minor
Signed-off-by: Roman Mazur <roman@balena.io>

package-lock.json

@@ -478,6 +478,12 @@
       "integrity": "sha512-d7c/C/+H/knZ3L8/cxhicHUiTDxdgap0b/aNJfsmLwFu/iOP17mdgbQsbHA3SJmrzsjD0l3UEE5SN4xxuz5ung==",
       "dev": true
     },
+    "@types/tmp": {
+      "version": "0.1.0",
+      "resolved": "https://registry.npmjs.org/@types/tmp/-/tmp-0.1.0.tgz",
+      "integrity": "sha512-6IwZ9HzWbCq6XoQWhxLpDjuADodH/MKXRUIDFudvgjcVdjFknvmR+DNsoUeer4XPrEnrZs04Jj+kfV9pFsrhmA==",
+      "dev": true
+    },
     "@types/tough-cookie": {
       "version": "2.3.4",
       "resolved": "https://registry.npmjs.org/@types/tough-cookie/-/tough-cookie-2.3.4.tgz",
@@ -2944,6 +2950,15 @@
           "resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-0.10.31.tgz",
           "integrity": "sha1-YuIDvEF2bGwoyfyEMB2rHFMQ+pQ=",
           "dev": true
+        },
+        "tmp": {
+          "version": "0.0.28",
+          "resolved": "https://registry.npmjs.org/tmp/-/tmp-0.0.28.tgz",
+          "integrity": "sha1-Fyc1t/YU6nrzlmT6hM8N5OUV0SA=",
+          "dev": true,
+          "requires": {
+            "os-tmpdir": "~1.0.1"
+          }
         }
       }
     },
@@ -10102,12 +10117,23 @@
       }
     },
     "tmp": {
-      "version": "0.0.28",
+      "version": "0.1.0",
-      "resolved": "https://registry.npmjs.org/tmp/-/tmp-0.0.28.tgz",
+      "resolved": "https://registry.npmjs.org/tmp/-/tmp-0.1.0.tgz",
-      "integrity": "sha1-Fyc1t/YU6nrzlmT6hM8N5OUV0SA=",
+      "integrity": "sha512-J7Z2K08jbGcdA1kkQpJSqLF6T0tdQqpR2pnSUXsIchbPdTI9v3e85cLW0d6WDhwuAleOV71j2xWs8qMPfK7nKw==",
       "dev": true,
       "requires": {
-        "os-tmpdir": "~1.0.1"
+        "rimraf": "^2.6.3"
+      },
+      "dependencies": {
+        "rimraf": {
+          "version": "2.6.3",
+          "resolved": "https://registry.npmjs.org/rimraf/-/rimraf-2.6.3.tgz",
+          "integrity": "sha512-mwqeW5XsA2qAejG46gYdENaxXjx9onRNCfn7L0duuP4hCuTIi/QO7PDK07KJfp1d+izWPrzEJDcSqBa0OZQriA==",
+          "dev": true,
+          "requires": {
+            "glob": "^7.1.3"
+          }
+        }
       }
     },
     "to-arraybuffer": {

package.json

@@ -57,6 +57,7 @@
     "@types/rwlock": "^5.0.2",
     "@types/shell-quote": "^1.6.0",
     "@types/sinon": "^7.0.13",
+    "@types/tmp": "^0.1.0",
     "balena-sync": "^10.0.0",
     "blinking": "~0.0.2",
     "bluebird": "^3.5.3",
@@ -110,6 +111,7 @@
     "sinon-chai": "^3.3.0",
     "strict-event-emitter-types": "^2.0.0",
     "terser": "^3.14.1",
+    "tmp": "^0.1.0",
     "ts-loader": "^5.3.0",
     "typed-error": "^2.0.0",
     "typescript": "^3.5.1",

src/local-mode.ts

@@ -1,12 +1,59 @@
 import * as Bluebird from 'bluebird';
 import * as Docker from 'dockerode';
 import * as _ from 'lodash';
-
 import Config from './config';
 import Database from './db';
+import log from './lib/supervisor-console';
 import { Logger } from './logger';
 
-import log from './lib/supervisor-console';
+// EngineSnapshot represents a list of containers, images, volumens, and networks present on the engine.
+// A snapshot is taken before entering local mode in order to perform cleanup when we exit local mode.
+export class EngineSnapshot {
+	constructor(
+		public readonly containers: string[],
+		public readonly images: string[],
+		public readonly volumes: string[],
+		public readonly networks: string[],
+	) {}
+
+	public static fromJSON(json: string): EngineSnapshot {
+		const obj = JSON.parse(json);
+		return new EngineSnapshot(
+			obj.containers,
+			obj.images,
+			obj.volumes,
+			obj.networks,
+		);
+	}
+
+	// Builds a new snapshot object that contains entities present in another snapshot,
+	// but not present in this one.
+	public diff(another: EngineSnapshot): EngineSnapshot {
+		return new EngineSnapshot(
+			_.difference(this.containers, another.containers),
+			_.difference(this.images, another.images),
+			_.difference(this.volumes, another.volumes),
+			_.difference(this.networks, another.networks),
+		);
+	}
+
+	public toString(): string {
+		return (
+			`containers [${this.containers}], ` +
+			`images [${this.images}], ` +
+			`volumes [${this.volumes}], ` +
+			`networks [${this.networks}]`
+		);
+	}
+}
+
+// Record in a database that stores EngineSnapshot.
+export class EngineSnapshotRecord {
+	constructor(
+		public readonly snapshot: EngineSnapshot,
+		public readonly timestamp: Date,
+	) {}
+}
 
 /**
  * This class handles any special cases necessary for switching
@@ -33,11 +80,7 @@ export class LocalModeManager {
 				// First switch the logger to it's correct state
 				this.logger.switchBackend(local);
 
-				// If we're leaving local mode, make sure to remove all of the
+				this.handleLocalModeStateChange(local);
-				// leftover artifacts
-				if (!local) {
-					this.removeLocalModeArtifacts();
-				}
 			}
 		});
 
@@ -56,51 +99,133 @@ export class LocalModeManager {
 
 		if (!localMode) {
 			// Remove any leftovers if necessary
-			await this.removeLocalModeArtifacts();
+			await this.handleLocalModeStateChange(false);
 		}
 	}
 
-	public async removeLocalModeArtifacts(): Promise<void> {
+	// Query the engine to get currently running containers and installed images.
-		try {
+	public async collectEngineSnapshot(): Promise<EngineSnapshotRecord> {
-			const images = await this.getLocalModeImages();
+		const containersPromise = this.docker
-			const containers = await this.getLocalModeContainers(images);
+			.listContainers()
+			.then(resp => _.map(resp, 'Id'));
+		const imagesPromise = this.docker
+			.listImages()
+			.then(resp => _.map(resp, 'Id'));
+		const volumesPromise = this.docker
+			.listVolumes()
+			.then(resp => _.map(resp.Volumes, 'Name'));
+		const networksPromise = this.docker
+			.listNetworks()
+			.then(resp => _.map(resp, 'Id'));
 
-			await Bluebird.map(containers, containerId => {
+		const data = await Bluebird.all([
-				log.debug('Removing local mode container: ', containerId);
+			containersPromise,
-				return this.docker.getContainer(containerId).remove({ force: true });
+			imagesPromise,
-			});
+			volumesPromise,
-			await Bluebird.map(images, imageId => {
+			networksPromise,
-				log.debug('Removing local mode image: ', imageId);
+		]);
-				return this.docker.getImage(imageId).remove({ force: true });
+		return new EngineSnapshotRecord(
-			});
+			new EngineSnapshot(data[0], data[1], data[2], data[3]),
-
+			new Date(),
-			// Remove any local mode state added to the database
-			await this.db
-				.models('app')
-				.del()
-				.where({ source: 'local' });
-		} catch (e) {
-			log.error('There was an error clearing local mode artifacts: ', e);
-		}
-	}
-
-	private async getLocalModeImages(): Promise<string[]> {
-		// Return all local mode images present on the local docker daemon
-		return _.map(
-			await this.docker.listImages({
-				filters: { label: ['io.resin.local.image=1'] },
-			}),
-			'Id',
 		);
 	}
 
-	private async getLocalModeContainers(
+	// Store engine snapshot data in the local database.
-		localModeImageIds: string[],
+	public async storeEngineSnapshot(record: EngineSnapshotRecord) {
-	): Promise<string[]> {
+		const timestamp = record.timestamp.toISOString();
-		return _(await this.docker.listContainers())
+		log.debug(
-			.filter(({ Image }) => _.includes(localModeImageIds, Image))
+			`Storing engine snapshot in the database. Timestamp: ${timestamp}`,
-			.map('Id')
+		);
-			.value();
+		await this.db.models('engineSnapshot').delete();
+		return this.db.models('engineSnapshot').insert({
+			snapshot: JSON.stringify(record.snapshot),
+			timestamp,
+		});
+	}
+
+	// Read the latest stored snapshot from the database.
+	public async retrieveLatestSnapshot(): Promise<EngineSnapshotRecord | null> {
+		const r = await this.db
+			.models('engineSnapshot')
+			.select()
+			.orderBy('rowid', 'DESC')
+			.first();
+
+		if (!r) {
+			return null;
+		}
+		return new EngineSnapshotRecord(
+			EngineSnapshot.fromJSON(r.snapshot),
+			new Date(Date.parse(r.timestamp)),
+		);
+	}
+
+	private async removeLocalModeArtifacts(objects: EngineSnapshot) {
+		log.debug(`Going to delete the following objects: ${objects}`);
+
+		// Delete engine objects. We catch every deletion error, so that we can attempt other objects deletions.
+		await Bluebird.map(objects.containers, cId => {
+			return this.docker
+				.getContainer(cId)
+				.remove({ force: true })
+				.catch(e => log.error(`Unable to delete container ${cId}`, e));
+		});
+		await Bluebird.map(objects.images, iId => {
+			return this.docker
+				.getImage(iId)
+				.remove({ force: true })
+				.catch(e => log.error(`Unable to delete image ${iId}`, e));
+		});
+		await Bluebird.map(objects.networks, nId => {
+			return this.docker
+				.getNetwork(nId)
+				.remove()
+				.catch(e => log.error(`Unable to delete network ${nId}`, e));
+		});
+		await Bluebird.map(objects.volumes, vId => {
+			return this.docker
+				.getVolume(vId)
+				.remove()
+				.catch(e => log.error(`Unable to delete volume ${vId}`, e));
+		});
+
+		// Remove any local mode state added to the database.
+		await this.db
+			.models('app')
+			.del()
+			.where({ source: 'local' })
+			.catch(e =>
+				log.error('Cannot delete local app entries in the database', e),
+			);
+	}
+
+	// Handle local mode state change.
+	// Input parameter is a target (new) state.
+	public async handleLocalModeStateChange(local: boolean) {
+		try {
+			const currentRecord = await this.collectEngineSnapshot();
+			if (local) {
+				return await this.storeEngineSnapshot(currentRecord);
+			}
+
+			const previousRecord = await this.retrieveLatestSnapshot();
+			if (!previousRecord) {
+				log.warn('Previous engine snapshot was not stored. Skipping clanup.');
+				return;
+			}
+
+			log.debug(
+				`Leaving local mode and cleaning up objects since ${previousRecord.timestamp.toISOString()}`,
+			);
+			return await this.removeLocalModeArtifacts(
+				currentRecord.snapshot.diff(previousRecord.snapshot),
+			);
+		} catch (e) {
+			log.error(
+				`Problems managing engine state on local mode switch. Local mode: ${local}.`,
+				e,
+			);
+		}
 	}
 }
 

src/migrations/20190619152500-engine-snapshot.js

@@ -0,0 +1,11 @@
+
+exports.up = (knex, Promise) => {
+	return knex.schema.createTable('engineSnapshot', (t) => {
+		t.string('snapshot'); // Engine snapshot encoded as JSON.
+		t.string('timestamp'); // When the snapshot was created.
+	});
+}
+
+exports.down = (knex, Promise) => {
+	return Promise.reject(new Error('Not Implemented'));
+}

test/local-mode.ts

@@ -0,0 +1,285 @@
+import { expect } from 'chai';
+import * as Docker from 'dockerode';
+import * as sinon from 'sinon';
+import * as tmp from 'tmp';
+import Config from '../src/config';
+import DB from '../src/db';
+import log from '../src/lib/supervisor-console';
+import LocalModeManager, {
+	EngineSnapshot,
+	EngineSnapshotRecord,
+} from '../src/local-mode';
+import Logger from '../src/logger';
+
+describe('LocalModeManager', () => {
+	let dbFile: tmp.FileResult;
+	let db: DB;
+	let localMode: LocalModeManager;
+	let dockerStub: sinon.SinonStubbedInstance<Docker>;
+
+	// Cleanup the database (to make sure nothing is left since last tests).
+	beforeEach(async () => {
+		await db.models('engineSnapshot').delete();
+	});
+
+	before(async () => {
+		dbFile = tmp.fileSync();
+		log.debug(`Test db: ${dbFile.name}`);
+		db = new DB({ databasePath: dbFile.name });
+		await db.init();
+
+		dockerStub = sinon.createStubInstance(Docker);
+		const configStub = (sinon.createStubInstance(Config) as unknown) as Config;
+		const loggerStub = (sinon.createStubInstance(Logger) as unknown) as Logger;
+
+		localMode = new LocalModeManager(
+			configStub,
+			(dockerStub as unknown) as Docker,
+			loggerStub,
+			db,
+		);
+	});
+
+	describe('EngineSnapshot', () => {
+		it('can calculate a diff', () => {
+			const original = new EngineSnapshot(
+				['c1', 'c2'],
+				['i1'],
+				['v1', 'v2'],
+				['nn'],
+			);
+			const newOne = new EngineSnapshot(
+				['c2', 'c3'],
+				['i1', 'i2', 'i3'],
+				['v1'],
+				[],
+			);
+			const diff = newOne.diff(original);
+
+			expect(diff.containers).to.deep.equal(['c3']);
+			expect(diff.images).to.deep.equal(['i2', 'i3']);
+			expect(diff.volumes).to.deep.equal([]);
+			expect(diff.networks).to.deep.equal([]);
+		});
+	});
+
+	describe('engine snapshots collection', () => {
+		before(() => {
+			// Stub the engine to return images, containers, volumes, and networks.
+			dockerStub.listImages.returns(
+				Promise.resolve([
+					{ Id: 'image-1' } as Docker.ImageInfo,
+					{ Id: 'image-2' } as Docker.ImageInfo,
+				]),
+			);
+			dockerStub.listContainers.returns(
+				Promise.resolve([
+					{ Id: 'container-1' } as Docker.ContainerInfo,
+					{ Id: 'container-2' } as Docker.ContainerInfo,
+				]),
+			);
+			dockerStub.listVolumes.returns(
+				Promise.resolve({
+					Volumes: [
+						{ Name: 'volume-1' } as Docker.VolumeInspectInfo,
+						{ Name: 'volume-2' } as Docker.VolumeInspectInfo,
+					],
+					Warnings: [],
+				}),
+			);
+			dockerStub.listNetworks.returns(
+				Promise.resolve([{ Id: 'network-1' }, { Id: 'network-2' }]),
+			);
+		});
+
+		it('collects all necessary engine entities', async () => {
+			const snapshotRecord = await localMode.collectEngineSnapshot();
+
+			expect(snapshotRecord.snapshot.containers).to.include(
+				'container-1',
+				'container-2',
+			);
+			expect(snapshotRecord.snapshot.images).to.include('image-1', 'image-2');
+			expect(snapshotRecord.snapshot.volumes).to.include(
+				'volume-1',
+				'volume-2',
+			);
+			expect(snapshotRecord.snapshot.networks).to.include(
+				'network-1',
+				'network-2',
+			);
+		});
+
+		it('marks snapshot with a timestamp', async () => {
+			const startTime = new Date();
+			const snapshotRecord = await localMode.collectEngineSnapshot();
+			expect(snapshotRecord.timestamp).to.be.at.least(startTime);
+		});
+
+		describe('local mode switch', () => {
+			const storeCurrentSnapshot = async (
+				containers: string[],
+				images: string[],
+				volumes: string[],
+				networks: string[],
+			) => {
+				await localMode.storeEngineSnapshot(
+					new EngineSnapshotRecord(
+						new EngineSnapshot(containers, images, volumes, networks),
+						new Date(),
+					),
+				);
+			};
+
+			interface RemoveableObject {
+				remove(): Promise<void>;
+			}
+
+			// Stub get<Object> methods on docker, so we can verify remove calls.
+			const stubRemoveMethods = (
+				removeThrows: boolean,
+			): Array<sinon.SinonStubbedInstance<RemoveableObject>> => {
+				const resArray: Array<
+					sinon.SinonStubbedInstance<RemoveableObject>
+				> = [];
+
+				const stub = <T>(
+					c: sinon.StubbableType<RemoveableObject>,
+					type: string,
+				) => {
+					const res = sinon.createStubInstance(c);
+					if (removeThrows) {
+						res.remove.rejects(`test error removing ${type}`);
+					} else {
+						res.remove.resolves();
+					}
+					resArray.push(res);
+					return (res as unknown) as T;
+				};
+				dockerStub.getImage.returns(stub(Docker.Image, 'image'));
+				dockerStub.getContainer.returns(stub(Docker.Container, 'container'));
+				dockerStub.getVolume.returns(stub(Docker.Volume, 'volume'));
+				dockerStub.getNetwork.returns(stub(Docker.Network, 'network'));
+				return resArray;
+			};
+
+			afterEach(() => {
+				dockerStub.getImage.resetHistory();
+				dockerStub.getContainer.resetHistory();
+				dockerStub.getVolume.resetHistory();
+				dockerStub.getNetwork.resetHistory();
+			});
+
+			it('stores new snapshot on local mode enter', async () => {
+				await localMode.handleLocalModeStateChange(true);
+
+				const snapshot = await localMode.retrieveLatestSnapshot();
+				expect(snapshot).to.be.not.null;
+			});
+
+			it('deletes newly created objects on local mode exit', async () => {
+				const removeStubs = stubRemoveMethods(false);
+				// All the objects returned by list<Objects> are not included into this snapshot.
+				// Hence, removal shoulf be called twice (stubbed methods return 2 objects per type).
+				await storeCurrentSnapshot(
+					['previous-container'],
+					['previous-image'],
+					['previous-volume'],
+					['previous-network'],
+				);
+
+				await localMode.handleLocalModeStateChange(false);
+
+				removeStubs.forEach(s => expect(s.remove.calledTwice).to.be.true);
+			});
+
+			it('keeps objects from the previous snapshot on local mode exit', async () => {
+				const removeStubs = stubRemoveMethods(false);
+				// With this snapshot, only <object>-2 must be removed from the engine.
+				await storeCurrentSnapshot(
+					['container-1'],
+					['image-1'],
+					['volume-1'],
+					['network-1'],
+				);
+
+				await localMode.handleLocalModeStateChange(false);
+
+				expect(dockerStub.getImage.calledWithExactly('image-2')).to.be.true;
+				expect(dockerStub.getContainer.calledWithExactly('container-2')).to.be
+					.true;
+				expect(dockerStub.getVolume.calledWithExactly('volume-2')).to.be.true;
+				expect(dockerStub.getNetwork.calledWithExactly('network-2')).to.be.true;
+				removeStubs.forEach(s => expect(s.remove.calledOnce).to.be.true);
+			});
+
+			it('logs but consumes cleanup errors on local mode exit', async () => {
+				const removeStubs = stubRemoveMethods(true);
+				// This snapshot will cause the logic to remove everything.
+				await storeCurrentSnapshot([], [], [], []);
+
+				// This should not throw.
+				await localMode.handleLocalModeStateChange(false);
+
+				// Even though remove method throws, we still attempt all removals.
+				removeStubs.forEach(s => expect(s.remove.calledTwice).to.be.true);
+			});
+
+			it('skips cleanup without previous snapshot on local mode exit', async () => {
+				const removeStubs = stubRemoveMethods(false);
+
+				await localMode.handleLocalModeStateChange(false);
+
+				expect(dockerStub.getImage.notCalled).to.be.true;
+				expect(dockerStub.getContainer.notCalled).to.be.true;
+				expect(dockerStub.getVolume.notCalled).to.be.true;
+				expect(dockerStub.getNetwork.notCalled).to.be.true;
+				removeStubs.forEach(s => expect(s.remove.notCalled).to.be.true);
+			});
+		});
+	});
+
+	describe('engine snapshot storage', () => {
+		const recordsCount = async () =>
+			await db
+				.models('engineSnapshot')
+				.count('* as cnt')
+				.first()
+				.then(r => r.cnt);
+
+		const recordSample = new EngineSnapshotRecord(
+			new EngineSnapshot(
+				['c1', 'c2'],
+				['i1', 'i2'],
+				['v1', 'v2'],
+				['n1', 'n2'],
+			),
+			new Date(),
+		);
+
+		it('returns null when snapshot is not stored', async () => {
+			expect(await recordsCount()).to.equal(0);
+			const retrieved = await localMode.retrieveLatestSnapshot();
+			expect(retrieved).to.be.null;
+		});
+
+		it('stores snapshot and retrieves from the db', async () => {
+			await localMode.storeEngineSnapshot(recordSample);
+			const retrieved = await localMode.retrieveLatestSnapshot();
+			console.log(retrieved);
+			expect(retrieved).to.be.deep.equal(recordSample);
+		});
+
+		it('rewrites previous snapshot', async () => {
+			await localMode.storeEngineSnapshot(recordSample);
+			await localMode.storeEngineSnapshot(recordSample);
+			await localMode.storeEngineSnapshot(recordSample);
+			expect(await recordsCount()).to.equal(1);
+		});
+	});
+
+	after(async () => {
+		sinon.restore();
+		dbFile.removeCallback();
+	});
+});