Merge pull request #1012 from balena-io/roman/local-mode-cleanup

Clean up local mode engine objects using snapshots
This commit is contained in:
Roman Mazur 2019-06-26 18:15:08 +03:00 committed by GitHub
commit 32082d5ecc
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
7 changed files with 645 additions and 47 deletions

40
package-lock.json generated
View File

@ -472,6 +472,18 @@
"integrity": "sha512-BFonQx849sYB2YOJZBUEfbWdaJcqRb6+ASvgUBtcmg2JRTjBaV2Wgn0SD0gWNIZ+rd7KPysPCjLUOUXnBDUlBg==",
"dev": true
},
"@types/sinon": {
"version": "7.0.13",
"resolved": "https://registry.npmjs.org/@types/sinon/-/sinon-7.0.13.tgz",
"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",
@ -2938,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"
}
}
}
},
@ -10096,12 +10117,23 @@
}
},
"tmp": {
"version": "0.0.28",
"resolved": "https://registry.npmjs.org/tmp/-/tmp-0.0.28.tgz",
"integrity": "sha1-Fyc1t/YU6nrzlmT6hM8N5OUV0SA=",
"version": "0.1.0",
"resolved": "https://registry.npmjs.org/tmp/-/tmp-0.1.0.tgz",
"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": {

View File

@ -56,6 +56,8 @@
"@types/request": "^2.48.1",
"@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",
@ -109,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",

View File

@ -983,3 +983,6 @@ module.exports = class ApplicationManager extends EventEmitter
return _.find app.services, (svc) ->
svc.serviceId == serviceId
.get('serviceName')
localModeSwitchCompletion: => @localModeManager.switchCompletion()

View File

@ -598,6 +598,8 @@ module.exports = class DeviceState extends EventEmitter
Promise.try =>
if !intermediate
@applyBlocker
.then =>
@applications.localModeSwitchCompletion()
.then =>
@usingInferStepsLock =>
@applications.getExtraStateForComparison()

View File

@ -4,9 +4,57 @@ 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 (
`${this.containers.length} containers, ` +
`${this.images.length} images, ` +
`${this.volumes.length} volumes, ` +
`${this.networks.length} 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
@ -24,6 +72,9 @@ export class LocalModeManager {
public db: Database,
) {}
// Indicates that switch from or to the local mode is not complete.
private switchInProgress: Bluebird<void> | null = null;
public async init() {
// Setup a listener to catch state changes relating to local mode
this.config.on('change', changed => {
@ -33,11 +84,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
// leftover artifacts
if (!local) {
this.removeLocalModeArtifacts();
}
this.startLocalModeChangeHandling(local);
}
});
@ -56,51 +103,174 @@ export class LocalModeManager {
if (!localMode) {
// Remove any leftovers if necessary
await this.removeLocalModeArtifacts();
await this.handleLocalModeStateChange(false);
}
}
public async removeLocalModeArtifacts(): Promise<void> {
try {
const images = await this.getLocalModeImages();
const containers = await this.getLocalModeContainers(images);
await Bluebird.map(containers, containerId => {
log.debug('Removing local mode container: ', containerId);
return this.docker.getContainer(containerId).remove({ force: true });
});
await Bluebird.map(images, imageId => {
log.debug('Removing local mode image: ', imageId);
return this.docker.getImage(imageId).remove({ force: true });
});
// 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);
}
public startLocalModeChangeHandling(local: boolean) {
this.switchInProgress = Bluebird.resolve(
this.handleLocalModeStateChange(local),
).finally(() => {
this.switchInProgress = null;
});
}
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',
// Query the engine to get currently running containers and installed images.
public async collectEngineSnapshot(): Promise<EngineSnapshotRecord> {
const containersPromise = this.docker
.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'));
const [containers, images, volumes, networks] = await Bluebird.all([
containersPromise,
imagesPromise,
volumesPromise,
networksPromise,
]);
return new EngineSnapshotRecord(
new EngineSnapshot(containers, images, volumes, networks),
new Date(),
);
}
private async getLocalModeContainers(
localModeImageIds: string[],
): Promise<string[]> {
return _(await this.docker.listContainers())
.filter(({ Image }) => _.includes(localModeImageIds, Image))
.map('Id')
.value();
private async cleanEngineSnapshots() {
await this.db.models('engineSnapshot').delete();
}
// Store engine snapshot data in the local database.
public async storeEngineSnapshot(record: EngineSnapshotRecord) {
const timestamp = record.timestamp.toISOString();
log.debug(
`Storing engine snapshot in the database. Timestamp: ${timestamp}`,
);
await this.cleanEngineSnapshots();
await this.db.models('engineSnapshot').insert({
snapshot: JSON.stringify(record.snapshot),
timestamp,
});
}
// Ensures an error is thrown id timestamp string cannot be parsed.
// Date.parse may both throw or return NaN depending on a case.
private static parseTimestamp(input: string): Date {
const ms = Date.parse(input);
if (isNaN(ms)) {
throw new Error('bad date string - got Nan parsing it');
}
return new Date(ms);
}
// 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;
}
try {
return new EngineSnapshotRecord(
EngineSnapshot.fromJSON(r.snapshot),
LocalModeManager.parseTimestamp(r.timestamp),
);
} catch (e) {
// Some parsing error happened. Ensure we add data details to the error description.
throw new Error(
`Cannot parse snapshot data ${JSON.stringify(r)}.` +
`Original message: [${e.message}].`,
);
}
}
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.info('Previous engine snapshot was not stored. Skipping cleanup.');
return;
}
log.debug(
`Leaving local mode and cleaning up objects since ${previousRecord.timestamp.toISOString()}`,
);
await this.removeLocalModeArtifacts(
currentRecord.snapshot.diff(previousRecord.snapshot),
);
await this.cleanEngineSnapshots();
} catch (e) {
log.error(
`Problems managing engine state on local mode switch. Local mode: ${local}.`,
e,
);
} finally {
log.debug('Handling of local mode switch is completed');
}
}
// Returns a promise to await local mode switch completion started previously.
public async switchCompletion() {
if (this.switchInProgress == null) {
return;
}
await this.switchInProgress;
}
}

View File

@ -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'));
}

377
test/local-mode.ts Normal file
View File

@ -0,0 +1,377 @@
import * as assert from 'assert';
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>;
const recordsCount = async () =>
await db
.models('engineSnapshot')
.count('* as cnt')
.first()
.then(r => r.cnt);
// 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);
});
it('can be awaited', async () => {
const removeStubs = stubRemoveMethods(false);
await storeCurrentSnapshot([], [], [], []);
// Run asynchronously (like on config change).
localMode.startLocalModeChangeHandling(false);
// Await like it's done by DeviceState.
await localMode.switchCompletion();
removeStubs.forEach(s => expect(s.remove.calledTwice).to.be.true);
});
it('cleans the last snapshot so that nothing is done on restart', async () => {
const removeStubs = stubRemoveMethods(false);
await storeCurrentSnapshot([], [], [], []);
await localMode.handleLocalModeStateChange(false);
// The database should be empty now.
expect(await recordsCount()).to.be.equal(0);
// This has to be no ops.
await localMode.handleLocalModeStateChange(false);
// So our stubs must be called only once.
// We delete 2 objects of each type during the first call, so number of getXXX and remove calls is 2.
expect(dockerStub.getImage.callCount).to.be.equal(2);
expect(dockerStub.getContainer.callCount).to.be.equal(2);
expect(dockerStub.getVolume.callCount).to.be.equal(2);
expect(dockerStub.getNetwork.callCount).to.be.equal(2);
removeStubs.forEach(s => expect(s.remove.callCount).to.be.equal(2));
});
it.only('skips cleanup in case of data corruption', async () => {
const removeStubs = stubRemoveMethods(false);
await db.models('engineSnapshot').insert({
snapshot: 'bad json',
timestamp: new Date().toISOString(),
});
localMode.startLocalModeChangeHandling(false);
await localMode.switchCompletion();
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 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);
});
describe('in case of data corruption', () => {
beforeEach(async () => {
await db.models('engineSnapshot').delete();
});
it('deals with snapshot data corruption', async () => {
// Write bad data to simulate corruption.
await db.models('engineSnapshot').insert({
snapshot: 'bad json',
timestamp: new Date().toISOString(),
});
try {
await localMode.retrieveLatestSnapshot();
assert.fail('Parsing error was expected');
} catch (e) {
console.log(e.message);
expect(e.message).to.contain('bad json');
}
});
it('deals with snapshot timestamp corruption', async () => {
// Write bad data to simulate corruption.
await db.models('engineSnapshot').insert({
snapshot:
'{"containers": [], "images": [], "volumes": [], "networks": []}',
timestamp: 'bad timestamp',
});
try {
await localMode.retrieveLatestSnapshot();
assert.fail('Parsing error was expected');
} catch (e) {
console.log(e.message);
expect(e.message).to.contain('bad timestamp');
}
});
});
});
after(async () => {
sinon.restore();
dbFile.removeCallback();
});
});