From 27bcc917b42709ab47f5a06191c649ed49815316 Mon Sep 17 00:00:00 2001 From: Christina Ying Wang <christina@balena.io> Date: Tue, 5 Dec 2023 13:14:39 -0800 Subject: [PATCH] Separate routes & actions, add tests for POST /v2/journal-logs Signed-off-by: Christina Ying Wang <christina@balena.io> --- src/device-api/actions.ts | 10 +++ src/device-api/v2.ts | 58 ++++++++--------- src/lib/journald.ts | 31 ++++++--- src/logging/monitor.ts | 4 +- test/integration/device-api/actions.spec.ts | 31 ++++++++- test/integration/device-api/v2.spec.ts | 33 ++++++++++ test/integration/lib/journald.spec.ts | 71 +++++++++++++++++++++ 7 files changed, 195 insertions(+), 43 deletions(-) create mode 100644 test/integration/lib/journald.spec.ts diff --git a/src/device-api/actions.ts b/src/device-api/actions.ts index f6eddc2bf1..d0280a40ae 100644 --- a/src/device-api/actions.ts +++ b/src/device-api/actions.ts @@ -27,6 +27,7 @@ import { NotFoundError, BadRequestError, } from '../lib/errors'; +import { JournalctlOpts, spawnJournalctl } from '../lib/journald'; /** * Run an array of healthchecks, outputting whether all passed or not @@ -464,3 +465,12 @@ export const cleanupVolumes = async ( withScope({ apps: [id] }), ); }; + +/** + * Spawn a journalctl process with the given options + * Used by: + * - POST /v2/journal-logs + */ +export const getLogStream = (opts: JournalctlOpts) => { + return spawnJournalctl(opts); +}; diff --git a/src/device-api/v2.ts b/src/device-api/v2.ts index 03e7bf5d07..2fd62d0886 100644 --- a/src/device-api/v2.ts +++ b/src/device-api/v2.ts @@ -12,7 +12,6 @@ import * as db from '../db'; import * as logger from '../logger'; import * as images from '../compose/images'; import * as serviceManager from '../compose/service-manager'; -import { spawnJournalctl } from '../lib/journald'; import log from '../lib/supervisor-console'; import supervisorVersion = require('../lib/supervisor-version'); import { checkInt, checkString, checkTruthy } from '../lib/validation'; @@ -533,34 +532,31 @@ router.get('/v2/cleanup-volumes', async (req: AuthorizedRequest, res, next) => { } }); -router.post('/v2/journal-logs', (req, res) => { - const all = checkTruthy(req.body.all); - const follow = checkTruthy(req.body.follow); - const count = checkInt(req.body.count, { positive: true }) || undefined; - const unit = req.body.unit; - const format = req.body.format || 'short'; - const containerId = req.body.containerId; - const since = req.body.since; - const until = req.body.until; - - const journald = spawnJournalctl({ - all, - follow, - count, - unit, - format, - containerId, - since, - until, - }); - res.status(200); - // We know stdout will be present - journald.stdout!.pipe(res); - res.on('close', () => { - journald.kill('SIGKILL'); - }); - journald.on('exit', () => { - journald.stdout!.unpipe(); - res.end(); - }); +router.post('/v2/journal-logs', (req, res, next) => { + try { + const opts = { + all: checkTruthy(req.body.all), + follow: checkTruthy(req.body.follow), + count: checkInt(req.body.count, { positive: true }), + unit: req.body.unit, + format: req.body.format, + containerId: req.body.containerId, + since: req.body.since, + until: req.body.until, + }; + + const journalProcess = actions.getLogStream(opts); + res.status(200); + + journalProcess.stdout.pipe(res); + res.on('close', () => { + journalProcess.kill('SIGKILL'); + }); + journalProcess.on('exit', () => { + journalProcess.stdout.unpipe(); + res.end(); + }); + } catch (e: unknown) { + next(e); + } }); diff --git a/src/lib/journald.ts b/src/lib/journald.ts index 6fb2f46dcc..e56792d236 100644 --- a/src/lib/journald.ts +++ b/src/lib/journald.ts @@ -1,6 +1,7 @@ import { ChildProcess, spawn } from 'child_process'; import log from './supervisor-console'; +import { Readable } from 'stream'; /** * Given a date integer in ms, return in a format acceptable by journalctl. @@ -13,17 +14,24 @@ import log from './supervisor-console'; export const toJournalDate = (timestamp: number): string => new Date(timestamp).toISOString().replace(/T/, ' ').replace(/\..+$/, ''); -export function spawnJournalctl(opts: { +export interface JournalctlOpts { all: boolean; follow: boolean; - count?: number | 'all'; unit?: string; containerId?: string; - format: string; - filterString?: string; + count?: number; since?: string; until?: string; -}): ChildProcess { + format?: string; + matches?: string; +} + +// A journalctl process has a non-null stdout +export interface JournalctlProcess extends ChildProcess { + stdout: Readable; +} + +export function spawnJournalctl(opts: JournalctlOpts): JournalctlProcess { const args: string[] = []; if (opts.all) { args.push('-a'); @@ -52,10 +60,15 @@ export function spawnJournalctl(opts: { args.push(opts.until); } args.push('-o'); - args.push(opts.format); - - if (opts.filterString) { - args.push(opts.filterString); + if (opts.format != null) { + args.push(opts.format); + } else { + args.push('short'); + } + // Filter logs by space-seperated matches per + // journalctl interface of `journalctl [OPTIONS..] [MATCHES..]` + if (opts.matches) { + args.push(opts.matches); } log.debug('Spawning journalctl', args.join(' ')); diff --git a/src/logging/monitor.ts b/src/logging/monitor.ts index 0df36d9dc8..0b46c40553 100644 --- a/src/logging/monitor.ts +++ b/src/logging/monitor.ts @@ -65,7 +65,7 @@ class LogMonitor { all: true, follow: true, format: 'json', - filterString: '_SYSTEMD_UNIT=balena.service', + matches: '_SYSTEMD_UNIT=balena.service', }, (row) => { if (row.CONTAINER_ID_FULL && this.containers[row.CONTAINER_ID_FULL]) { @@ -148,7 +148,7 @@ class LogMonitor { all: true, follow: false, format: 'json', - filterString: `CONTAINER_ID_FULL=${containerId}`, + matches: `CONTAINER_ID_FULL=${containerId}`, since: toJournalDate(lastSentTimestamp + 1), // increment to exclude last sent log }, (row) => this.handleRow(row), diff --git a/test/integration/device-api/actions.spec.ts b/test/integration/device-api/actions.spec.ts index 77f10bfe4b..5489e9fb16 100644 --- a/test/integration/device-api/actions.spec.ts +++ b/test/integration/device-api/actions.spec.ts @@ -15,7 +15,8 @@ import * as TargetState from '~/src/device-state/target-state'; import * as applicationManager from '~/src/compose/application-manager'; import { cleanupDocker } from '~/test-lib/docker-helper'; -import { exec } from '~/src/lib/fs-utils'; +import { exec } from '~/lib/fs-utils'; +import * as journald from '~/lib/journald'; export async function dbusSend( dest: string, @@ -913,3 +914,31 @@ describe('cleans up orphaned volumes', () => { expect(getAndRemoveOrphanedVolumesStub).to.have.been.calledOnce; }); }); + +describe('spawns a journal process', () => { + // This action simply calls spawnJournalctl which we test in + // journald.spec.ts, so we can just stub it here + let spawnJournalctlStub: SinonStub; + before(() => { + spawnJournalctlStub = stub(journald, 'spawnJournalctl'); + }); + after(() => { + spawnJournalctlStub.restore(); + }); + + it('spawns a journal process through journald', async () => { + const opts = { + all: true, + follow: true, + unit: 'test-unit', + containerId: 'test-container-id', + count: 10, + since: '2019-01-01 00:00:00', + until: '2019-01-01 01:00:00', + format: 'json', + matches: '_SYSTEMD_UNIT=test-unit', + }; + await actions.getLogStream(opts); + expect(spawnJournalctlStub).to.have.been.calledOnceWith(opts); + }); +}); diff --git a/test/integration/device-api/v2.spec.ts b/test/integration/device-api/v2.spec.ts index fff78f0a7c..688a3d5643 100644 --- a/test/integration/device-api/v2.spec.ts +++ b/test/integration/device-api/v2.spec.ts @@ -772,4 +772,37 @@ describe('device-api/v2', () => { .expect(503); }); }); + + describe('POST /v2/journal-logs', () => { + // Actions are tested elsewhere so we can stub the dependency here + let getLogStreamStub: SinonStub; + before(() => { + getLogStreamStub = stub(actions, 'getLogStream'); + }); + after(() => { + getLogStreamStub.restore(); + }); + + it('responds with 200 and pipes journal stdout to response', async () => { + getLogStreamStub.callThrough(); + + await request(api) + .post('/v2/journal-logs') + .set('Authorization', `Bearer ${await deviceApi.getGlobalApiKey()}`) + .expect(200) + .then(({ text }) => { + // journalctl in the sut service should be empty + // as we don't log to it during testing + expect(text).to.equal('-- No entries --\n'); + }); + }); + + it('responds with 503 if an error occurred', async () => { + getLogStreamStub.throws(new Error()); + await request(api) + .post('/v2/journal-logs') + .set('Authorization', `Bearer ${await deviceApi.getGlobalApiKey()}`) + .expect(503); + }); + }); }); diff --git a/test/integration/lib/journald.spec.ts b/test/integration/lib/journald.spec.ts new file mode 100644 index 0000000000..ff35dc881c --- /dev/null +++ b/test/integration/lib/journald.spec.ts @@ -0,0 +1,71 @@ +import { expect } from 'chai'; +import { ChildProcess } from 'child_process'; + +import { toJournalDate, spawnJournalctl } from '~/src/lib/journald'; + +describe('lib/journald', () => { + describe('toJournalDate', () => { + it('should convert a timestamp in ms to a journalctl date', () => { + const journalDate = toJournalDate( + new Date('2019-01-01T00:00:00.000Z').getTime(), + ); + expect(journalDate).to.equal('2019-01-01 00:00:00'); + }); + }); + + describe('spawnJournalctl', () => { + it('should spawn a journalctl process with defaults', () => { + const journalProcess = spawnJournalctl({ + all: false, + follow: false, + }); + + expect(journalProcess).to.have.property('stdout'); + expect(journalProcess).to.be.instanceOf(ChildProcess); + expect(journalProcess) + .to.have.property('spawnargs') + .that.deep.equals(['journalctl', '-o', 'short']); + + journalProcess.kill('SIGKILL'); + }); + + it('should spawn a journalctl process with valid options', () => { + const journalProcess = spawnJournalctl({ + all: true, + follow: true, + unit: 'test-unit', + containerId: 'test-container', + count: 10, + since: '2019-01-01 00:00:00', + until: '2019-01-02 00:00:00', + format: 'json', + matches: '_SYSTEMD_UNIT=test-unit', + }); + + expect(journalProcess).to.have.property('stdout'); + expect(journalProcess).to.be.instanceOf(ChildProcess); + expect(journalProcess) + .to.have.property('spawnargs') + .that.deep.equals([ + 'journalctl', + '-a', + '--follow', + '-u', + 'test-unit', + '-t', + 'test-container', + '-n', + '10', + '-S', + '2019-01-01 00:00:00', + '-U', + '2019-01-02 00:00:00', + '-o', + 'json', + '_SYSTEMD_UNIT=test-unit', + ]); + + journalProcess.kill('SIGKILL'); + }); + }); +});