From beeeb31b3c9a7da5c2eeeba303ce661067cd5847 Mon Sep 17 00:00:00 2001 From: Christopher Hiller Date: Wed, 2 Nov 2022 18:11:08 -0700 Subject: [PATCH] chore(test): add unit tests for RokuDebugWriter --- lib/debug/writer.js | 61 ++++++++--- test/unit/debug/writer.spec.js | 192 +++++++++++++++++++++++++++++++++ 2 files changed, 237 insertions(+), 16 deletions(-) create mode 100644 test/unit/debug/writer.spec.js diff --git a/lib/debug/writer.js b/lib/debug/writer.js index 691ec19e..0ff3f71d 100644 --- a/lib/debug/writer.js +++ b/lib/debug/writer.js @@ -1,13 +1,13 @@ -import {pipeline} from 'node:stream/promises'; import {fs} from 'appium/support'; -import log from '../logger'; -import _ from 'lodash'; import B from 'bluebird'; +import envPaths from 'env-paths'; +import _ from 'lodash'; +import {EventEmitter} from 'node:events'; import _fs from 'node:fs'; import path from 'node:path'; -import envPaths from 'env-paths'; +import {pipeline} from 'node:stream/promises'; import {lock} from 'proper-lockfile'; -import {EventEmitter} from 'node:events'; +import log from '../logger'; import {DEFAULT_DEBUG_CLIENT_OPTS, RokuDebugClient} from './client'; /** @@ -82,12 +82,13 @@ export class RokuDebugWriter extends EventEmitter { const {logDirpath, lockfileDirpath} = RokuDebugWriter.getEnvPaths(); + this.#client = new RokuDebugClient(host, opts); + if (!this.#opts.logPath) { const logFileBasename = `debug-${this.#client.hostSlug}.log`; this.#opts.logPath = path.join(logDirpath, logFileBasename); } - this.#client = new RokuDebugClient(host, opts); this.#lockfileDirpath = lockfileDirpath; this.#logDirpath = logDirpath; this.#ac = new AbortController(); @@ -161,9 +162,10 @@ export class RokuDebugWriter extends EventEmitter { * @returns {_fs.WriteStream} */ #createLogfileStream() { - return _fs.createWriteStream(this.logPath, { + return fs.createWriteStream(this.logPath, { fd: this.#opts.logFd, encoding: 'utf8', + flags: 'a+' }); } @@ -171,16 +173,43 @@ export class RokuDebugWriter extends EventEmitter { * Configure a pipe from the connected telnet client to the log file */ async pipe() { - await this.#client.connect(); - await this.#prepareFs(); + const handleAbort = () => { + log.debug(`Debug log pipe to ${this.logPath} aborted`); + this.#ac = new AbortController(); + }; + + if (this.#ac.signal.aborted) { + return handleAbort(); + } + + await B.all([this.#client.connect(), this.#prepareFs]); + + if (this.#ac.signal.aborted) { + return handleAbort(); + } + this.#_unlock = await this.#lockLogfile(); - await pipeline(this.#client, this.#createLogfileStream(), {signal: this.#ac.signal}); - // XXX does this happen before or after client 'close' event? - if (!this.#opts.keepLogs) { - try { - await fs.unlink(this.logPath); - } catch (err) { - log.warn(err); + + if (this.#ac.signal.aborted) { + return handleAbort(); + } + + try { + await pipeline(this.#client, this.#createLogfileStream(), {signal: this.#ac.signal}); + } catch (err) { + if (this.#ac.signal.aborted) { + handleAbort(); + } else { + log.error(err); + } + } finally { + // XXX does this happen before or after client 'close' event? + if (!this.#opts.keepLogs) { + try { + await fs.unlink(this.logPath); + } catch (err) { + log.warn(err); + } } } } diff --git a/test/unit/debug/writer.spec.js b/test/unit/debug/writer.spec.js new file mode 100644 index 00000000..22c1fd89 --- /dev/null +++ b/test/unit/debug/writer.spec.js @@ -0,0 +1,192 @@ +/* eslint-disable promise/prefer-await-to-callbacks */ +import * as stream from 'node:stream'; +import rewiremock from 'rewiremock/node'; +import {createSandbox} from 'sinon'; +import unexpected from 'unexpected'; +import unexpectedSinon from 'unexpected-sinon'; +const expect = unexpected.clone().use(unexpectedSinon); + +describe('RokuDebugWriter', function () { + /** @type {typeof import('../../../lib/debug/writer').RokuDebugWriter} */ + let RokuDebugWriter; + + /** @type {sinon.SinonSandbox} */ + let sandbox; + + let MockAppiumSupport; + + let mockClient; + + /** @type {Writable} */ + let writable; + + beforeEach(function () { + sandbox = createSandbox(); + + writable = new stream.Writable({ + write: sandbox.stub().callsArgAsync(2), + defaultEncoding: 'utf-8', + }); + + MockAppiumSupport = { + fs: { + mkdirp: sandbox.stub().resolves(), + createWriteStream: sandbox.stub().returns(writable), + unlink: sandbox.stub().resolves(), + }, + logger: { + getLogger: sandbox.stub().callsFake(() => MockAppiumSupport.logger.__logger), + __logger: sandbox.stub(new global.console.Console(process.stdout, process.stderr)), + }, + }; + + // XXX: I'm not sure how to get utf-8 out of this stream, because + // `writable` is not called with a utf-8 string... + mockClient = Object.assign( + stream.Readable.from(['a log message', 'another log message', 'yet another log message'], { + encoding: 'utf-8', + }), + { + hostSlug: 'localhost', + connect: sandbox.stub().resolves(), + } + ); + sandbox.spy(mockClient, 'on'); + + ({RokuDebugWriter} = rewiremock.proxy(() => require('../../../lib/debug/writer'), { + 'node:fs': {}, + 'env-paths': sandbox.stub().returns({temp: '/tmp', log: '/var/log'}), + 'appium/support': MockAppiumSupport, + 'proper-lockfile': { + lock: sandbox.stub(), + }, + '../../../lib/debug/client': { + DEFAULT_DEBUG_CLIENT_OPTS: {}, + RokuDebugClient: sandbox.stub().returns(mockClient), + }, + })); + }); + + describe('constructor', function () { + it('should instantiate a RokuDebugWriter', function () { + expect(new RokuDebugWriter('localhost'), 'to be a', RokuDebugWriter); + }); + + it('should listen for the "close" event of its RokuDebugClient instance', function () { + new RokuDebugWriter('localhost'); + expect(mockClient.on, 'to have a call satisfying', ['close', expect.it('to be a function')]); + }); + + describe('when provided no explicit logPath', function () { + it('should create a logPath based on hostname', function () { + const writer = new RokuDebugWriter('localhost'); + expect(writer.logPath, 'to equal', '/var/log/debug-localhost.log'); + }); + }); + + describe('when provided an explicit logPath', function () { + it('should use the logPath', function () { + const writer = new RokuDebugWriter('localhost', {logPath: '/var/log/roku.log'}); + expect(writer.logPath, 'to equal', '/var/log/roku.log'); + }); + }); + }); + + describe('static method', function () { + describe('getEnvPaths()', function () { + it('should return a log dir and lockfile dir', function () { + expect(RokuDebugWriter.getEnvPaths(), 'to equal', { + logDirpath: '/var/log', + lockfileDirpath: '/tmp', + }); + }); + }); + }); + + describe('instance property', function () { + /** @type {RokuDebugWriter} */ + let writer; + + beforeEach(function () { + writer = new RokuDebugWriter('localhost'); + }); + + it('should be a string', function () { + expect(writer.logPath, 'to be a string'); + }); + }); + + describe('instance method', function () { + /** @type {RokuDebugWriter} */ + let writer; + + beforeEach(function () { + writer = new RokuDebugWriter('localhost'); + }); + + describe('pipe()', function () { + it('should write the logs from the client to a file', async function () { + await writer.pipe(); + expect(writable._write, 'to have calls satisfying', [ + [Buffer.from('a log message'), 'buffer', expect.it('to be a function')], + [Buffer.from('another log message'), 'buffer', expect.it('to be a function')], + [Buffer.from('yet another log message'), 'buffer', expect.it('to be a function')], + ]); + }); + + describe('when the client emits an error', function () { + let err; + + beforeEach(function () { + err = new Error('some error'); + mockClient._read = sandbox.stub().callsFake(() => { + mockClient.emit('error', err); + }); + }); + + it('should log an error', async function () { + await writer.pipe(); + expect(MockAppiumSupport.logger.__logger.error, 'to have a call satisfying', [err]); + }); + }); + + describe('when "keepLogs" is false', function () { + beforeEach(function () { + writer = new RokuDebugWriter('localhost', {keepLogs: false}); + }); + it('should delete the logfile', async function () { + await writer.pipe(); + expect(MockAppiumSupport.fs.unlink, 'to have a call satisfying', [writer.logPath]); + }); + + describe('when deletion fails', function () { + it('should log a warning', async function () { + const err = new Error('some error'); + MockAppiumSupport.fs.unlink.rejects(err); + await writer.pipe(); + expect(MockAppiumSupport.logger.__logger.warn, 'to have a call satisfying', [err]); + }); + }); + }); + }); + + describe('unpipe', function () { + it('should halt writing', async function () { + // XXX the behavior here seems nondeterministic. + // pipe() contains at minimum three async calls, and the abort could happen + // any time between them. + const promise = writer.pipe(); + writer.unpipe(); + await promise; + // ... which is why all I can do is check the debug log + expect(MockAppiumSupport.logger.__logger.debug, 'to have a call satisfying', [ + 'Debug log pipe to /var/log/debug-localhost.log aborted', + ]); + }); + }); + }); + + afterEach(function () { + sandbox.restore(); + }); +});