balena-supervisor/test/11-logger.spec.ts
Cameron Diver 9e0c99e797 tests: Clean up and consistify naming scheme
Change-type: patch
Signed-off-by: Cameron Diver <cameron@balena.io>
2020-10-12 14:41:21 +01:00

144 lines
4.2 KiB
TypeScript

import * as https from 'https';
import * as stream from 'stream';
import * as zlib from 'zlib';
import * as Promise from 'bluebird';
import { expect } from './lib/chai-config';
import * as sinon from 'sinon';
import { ContainerLogs } from '../src/logging/container';
import * as config from '../src/config';
describe('Logger', function () {
let logger: typeof import('../src/logger');
let configStub: sinon.SinonStub;
beforeEach(async function () {
this._req = new stream.PassThrough();
this._req.flushHeaders = sinon.spy();
this._req.end = sinon.spy();
this._req.body = '';
this._req.pipe(zlib.createGunzip()).on('data', (chunk: Buffer) => {
this._req.body += chunk;
});
this.requestStub = sinon.stub(https, 'request').returns(this._req);
configStub = sinon.stub(config, 'getMany').returns(
// @ts-ignore this should actually work but the type system doesnt like it
Promise.resolve({
apiEndpoint: 'https://example.com',
uuid: 'deadbeef',
deviceApiKey: 'secretkey',
unmanaged: false,
loggingEnabled: true,
localMode: false,
}),
);
// delete the require cache for the logger module so we can force a refresh
delete require.cache[require.resolve('../src/logger')];
logger = await import('../src/logger');
await logger.initialized;
});
afterEach(function () {
this.requestStub.restore();
configStub.restore();
});
after(function () {
delete require.cache[require.resolve('../src/logger')];
});
it('waits the grace period before sending any logs', function () {
const clock = sinon.useFakeTimers();
logger.log({ message: 'foobar', serviceId: 15 });
clock.tick(4999);
clock.restore();
return Promise.delay(100).then(() => {
expect(this._req.body).to.equal('');
});
});
it('tears down the connection after inactivity', function () {
const clock = sinon.useFakeTimers();
logger.log({ message: 'foobar', serviceId: 15 });
clock.tick(61000);
clock.restore();
return Promise.delay(100).then(() => {
expect(this._req.end.calledOnce).to.be.true;
});
});
it('sends logs as gzipped ndjson', function () {
const timestamp = Date.now();
logger.log({ message: 'foobar', serviceId: 15 });
logger.log({ timestamp: 1337, message: 'foobar', serviceId: 15 });
logger.log({ message: 'foobar' }); // shold be ignored
return Promise.delay(5500).then(() => {
expect(this.requestStub.calledOnce).to.be.true;
const opts = this.requestStub.firstCall.args[0];
expect(opts.href).to.equal(
'https://example.com/device/v2/deadbeef/log-stream',
);
expect(opts.method).to.equal('POST');
expect(opts.headers).to.deep.equal({
Authorization: 'Bearer secretkey',
'Content-Type': 'application/x-ndjson',
'Content-Encoding': 'gzip',
});
const lines = this._req.body.split('\n');
expect(lines.length).to.equal(3);
expect(lines[2]).to.equal('');
let msg = JSON.parse(lines[0]);
expect(msg).to.have.property('message').that.equals('foobar');
expect(msg).to.have.property('serviceId').that.equals(15);
expect(msg).to.have.property('timestamp').that.is.at.least(timestamp);
msg = JSON.parse(lines[1]);
expect(msg).to.deep.equal({
timestamp: 1337,
message: 'foobar',
serviceId: 15,
});
});
});
it('allows logging system messages which are also reported to the eventTracker', function () {
const timestamp = Date.now();
logger.logSystemMessage(
'Hello there!',
{ someProp: 'someVal' },
'Some event name',
);
return Promise.delay(5500).then(() => {
const lines = this._req.body.split('\n');
expect(lines.length).to.equal(2);
expect(lines[1]).to.equal('');
const msg = JSON.parse(lines[0]);
expect(msg).to.have.property('message').that.equals('Hello there!');
expect(msg).to.have.property('isSystem').that.equals(true);
expect(msg).to.have.property('timestamp').that.is.at.least(timestamp);
});
});
it('should support non-tty log lines', function () {
const message =
'\u0001\u0000\u0000\u0000\u0000\u0000\u0000?2018-09-21T12:37:09.819134000Z this is the message';
const buffer = Buffer.from(message);
// @ts-ignore accessing a private function
expect(ContainerLogs.extractMessage(buffer)).to.deep.equal({
message: 'this is the message',
timestamp: 1537533429819,
});
});
});