Skip to content

Commit

Permalink
Reimplemented SimulatorLogPlugin to use log stream (#1428)
Browse files Browse the repository at this point in the history 
* feat(artifacts): reimplemented SimulatorLogPlugin

* code(artifacts): test.log -> process.log
  • Loading branch information
@noomorph @LeoNatan
noomorph authored and LeoNatan committed Jun 4, 2019
1 parent 6d5fc1b commit f7d08f5
Show file tree
Hide file tree
Showing 7 changed files with 159 additions and 188 deletions.
4 changes: 2 additions & 2 deletions detox/src/artifacts/log/LogArtifactPlugin.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,8 +23,8 @@ class LogArtifactPlugin extends StartupAndTestRecorderPlugin {
}

async preparePathForTestArtifact(testSummary) {
return this.api.preparePathForArtifact('test.log', testSummary);
return this.api.preparePathForArtifact('process.log', testSummary);
}
}

module.exports = LogArtifactPlugin;
module.exports = LogArtifactPlugin;
37 changes: 12 additions & 25 deletions detox/src/artifacts/log/ios/SimulatorLogPlugin.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,52 +11,39 @@ class SimulatorLogPlugin extends LogArtifactPlugin {

async onBeforeShutdownDevice(event) {
await super.onBeforeShutdownDevice(event);
await this._tryStopCurrentRecording();
await this._tryToStopCurrentRecording();
}

async onBeforeUninstallApp(event) {
await super.onBeforeUninstallApp(event);
await this._tryStopCurrentRecording();
async onBeforeLaunchApp(event) {
await super.onBeforeLaunchApp(event);
await this._tryToLaunchCurrentRecording();
}

async onBeforeTerminateApp(event) {
await super.onBeforeTerminateApp(event);
await this._tryStopCurrentRecording();
}

async onLaunchApp(event) {
await super.onLaunchApp(event);

async _tryToLaunchCurrentRecording() {
if (this.currentRecording) {
await this.currentRecording.start({
readFromBeginning: true,
udid: this.context.deviceId,
bundleId: this.context.bundleId,
});
}
}

async _tryStopCurrentRecording() {
async _tryToStopCurrentRecording() {
if (this.currentRecording) {
await this.currentRecording.stop();
}
}

createStartupRecording() {
return this._createRecording(true);
return this.createTestRecording();
}

createTestRecording() {
return this._createRecording(false);
}

_createRecording(readFromBeginning) {
const udid = this.context.deviceId;
const { stdout, stderr } = this.appleSimUtils.getLogsPaths(udid);

return new SimulatorLogRecording({
udid: this.context.deviceId,
bundleId: this.context.bundleId,
appleSimUtils: this.appleSimUtils,
temporaryLogPath: tempfile('.log'),
logStderr: stderr,
logStdout: stdout,
readFromBeginning,
});
}
}
Expand Down
102 changes: 50 additions & 52 deletions detox/src/artifacts/log/ios/SimulatorLogPlugin.test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,16 +2,16 @@ jest.mock('../../../utils/argparse');
jest.mock('../../../utils/logger');

const _ = require('lodash');
const os = require('os');
const tempfile = require('tempfile');
const fs = require('fs-extra');
const exec = require('../../../utils/exec');
const path = require('path');
const sleep = require('../../../utils/sleep');

describe('SimulatorLogPlugin', () => {
async function majorWorkflow() {
let argparse = null;
let fakePathBuilder = null;
let fakeSources = null;
let fakeAppleSimUtils = null;
let artifactsManager = null;
let SimulatorLogPlugin = null;
Expand Down Expand Up @@ -42,15 +42,27 @@ describe('SimulatorLogPlugin', () => {
}),
};

fakeAppleSimUtils = {
logs: Object.freeze({
stdout: tempfile('.stdout.log'),
stderr: tempfile('.stderr.log'),
}),
fakeSources = {
stdin: tempfile('.stdin.log'),
};

getLogsPaths() {
return this.logs;
}
fakeAppleSimUtils = {
logStream({ udid, processImagePath, level, stdout, stderr }) {
fs.writeFileSync(fakeSources.stdin, '');

const handle = fs.openSync(fakeSources.stdin, 'r');
const process = exec.spawnAndLog('cat', [], {
stdio: [handle, stdout, stderr],
silent: true,
});

process.catch(e => e).then(() => fs.close(handle));

return process;
},
getAppContainer(udid, bundleId) {
return `/path/to/simulators/${udid}/apps/${bundleId}.app`;
},
};

artifactsManager = new ArtifactsManager(fakePathBuilder);
Expand All @@ -63,78 +75,64 @@ describe('SimulatorLogPlugin', () => {
}

async function logToDeviceLogs(line) {
await Promise.all([
fs.appendFile(fakeAppleSimUtils.logs.stdout, line + '\n'),
fs.appendFile(fakeAppleSimUtils.logs.stderr, line + '\n'),
]);
}

async function deleteDeviceLogs() {
await Promise.all([
fs.remove(fakeAppleSimUtils.logs.stdout),
fs.remove(fakeAppleSimUtils.logs.stderr),
]);
await fs.appendFile(fakeSources.stdin, line + '\n');
await fs.readFile(fakeSources.stdin, 'utf8');
}

await init();
await artifactsManager.onBootDevice({ deviceId: 'booted' });
await logToDeviceLogs('after boot');
await logToDeviceLogs('omit - after boot');

await artifactsManager.onBeforeLaunchApp({ device: 'booted', bundleId: 'com.test' });
await deleteDeviceLogs();

await logToDeviceLogs('during launch inside detox.init()');
await logToDeviceLogs('omit - during launch inside detox.init()');
await artifactsManager.onLaunchApp({ device: 'booted', bundleId: 'com.test', pid: 8000 });
await logToDeviceLogs('after launch inside detox.init()');
await logToDeviceLogs('omit - after launch inside detox.init()');

await artifactsManager.onBeforeAll();
await logToDeviceLogs('inside before all');

if (os.platform() !== 'darwin') {
await sleep(1000); // HACK: till we replace `tail` with something less flaky
}
await logToDeviceLogs('take - inside before all');

await artifactsManager.onBeforeEach({ title: 'test', fullName: 'some test', status: 'running'});
await logToDeviceLogs('inside before each');
await logToDeviceLogs('take - inside before each');

await logToDeviceLogs('before relaunch inside test');
await logToDeviceLogs('take - before relaunch inside test');
await artifactsManager.onBeforeLaunchApp({ device: 'booted', bundleId: 'com.test' });
await deleteDeviceLogs();
await logToDeviceLogs('during relaunch inside test');
await logToDeviceLogs('take - during relaunch inside test');
await artifactsManager.onLaunchApp({ device: 'booted', bundleId: 'com.test', pid: 8001 });
await logToDeviceLogs('after relaunch inside test');
await logToDeviceLogs('take - after relaunch inside test');

await artifactsManager.onAfterEach({ title: 'test', fullName: 'some test', status: 'passed'});
await logToDeviceLogs('after afterEach');
await logToDeviceLogs('omit - after afterEach');
await artifactsManager.onAfterAll();
await logToDeviceLogs('after afterAll');
await logToDeviceLogs('omit - after afterAll');

const result = {};

expect(fakePathBuilder.buildPathForTestArtifact).toHaveBeenCalledTimes(2);
for (const artifact of createdArtifacts) {
const contents = (await fs.readFile(artifact, 'utf8')).split('\n');
const contents = (await fs.readFile(artifact, 'utf8')).trim().split('\n');
const extension = path.basename(artifact).split('.').slice(1).join('.');

result[`stdout.${extension}`] = contents.filter(s => s.indexOf('stdout: ') === 0);
result[`stderr.${extension}`] = contents.filter(s => s.indexOf('stderr: ') === 0);
result[extension] = contents;
}

const allCreatedFiles = [...Object.values(fakeAppleSimUtils.logs), ...createdArtifacts];
const allCreatedFiles = [...Object.values(fakeSources), ...createdArtifacts];
await Promise.all(allCreatedFiles.map(filename => fs.remove(filename)));

return result;
}

it('should work consistently in a stressed environment, through-out boots, launches and relaunches', async () => {
// const results = await Promise.all(_.times(100, majorWorkflow));
//
// for (const [snapshotName, value] of Object.entries(results[0])) {
// expect(value).toMatchSnapshot(snapshotName);
// }
//
// for (const result of results) {
// expect(result).toEqual(results[0]);
// }
it.skip('should work through-out boots, launches and relaunches', async () => {
const snapshots = await majorWorkflow();
for (const [snapshotName, value] of Object.entries(snapshots)) {
expect(value).toMatchSnapshot(snapshotName);
}
});

it.skip('should work consistently in a stressed environment', async () => {
const results = await Promise.all(_.times(16, majorWorkflow));

for (const result of results) {
expect(result).toEqual(results[0]);
}
});
});
113 changes: 37 additions & 76 deletions detox/src/artifacts/log/ios/SimulatorLogRecording.js
View file
Original file line number Diff line number Diff line change
@@ -1,106 +1,67 @@
const _ = require('lodash');
const fs = require('fs-extra');
const log = require('../../../utils/logger').child({ __filename });
const sleep = require('../../../utils/sleep');
const { Tail } = require('tail');
const exec = require('../../../utils/exec');
const Artifact = require('../../templates/artifact/Artifact');

class SimulatorLogRecording extends Artifact {
constructor({
logStderr,
logStdout,
readFromBeginning,
udid,
bundleId,
appleSimUtils,
temporaryLogPath,
}) {
super();

this._readFromBeginning = readFromBeginning;
this._udid = udid;
this._bundleId = bundleId;
this._appleSimUtils = appleSimUtils;
this._logPath = temporaryLogPath;
this._stdoutPath = logStdout;
this._stderrPath = logStderr;

this._logStream = null;
this._stdoutTail = null;
this._stderrTail = null;
this._logContext = null;
}

async doStart({ readFromBeginning } = {}) {
if (readFromBeginning !== void 0) {
this._readFromBeginning = readFromBeginning;
}

this._logStream = this._logStream || this._openWriteableStream();
this._stdoutTail = await this._createTail(this._stdoutPath, 'stdout');
this._stderrTail = await this._createTail(this._stderrPath, 'stderr');
async doStart({ udid, bundleId } = {}) {
if (udid) {this._udid = udid; }
if (bundleId) {this._bundleId = bundleId; }

await fs.ensureFile(this._logPath);
const fileHandle = await fs.open(this._logPath, 'a');

this._logContext = {
fileHandle,
throttle: sleep(100),
process: this._appleSimUtils.logStream({
udid: this._udid,
processImagePath: await this._getProcessImagePath(),
stdout: fileHandle,
level: 'debug',
style: 'compact',
}),
};
}

async doStop() {
await this._unwatch();
if (this._logContext) {
const { fileHandle, throttle, process } = this._logContext;
await throttle;
await exec.interruptProcess(process, 'SIGTERM');
await fs.close(fileHandle);
this._logContext = null;
}
}

async doSave(artifactPath) {
await this._closeWriteableStream();
await Artifact.moveTemporaryFile(log, this._logPath, artifactPath);
}

async doDiscard() {
await this._closeWriteableStream();
await fs.remove(this._logPath);
}

_openWriteableStream() {
log.trace({ event: 'CREATE_STREAM '}, `creating append-only stream to: ${this._logPath}`);
return fs.createWriteStream(this._logPath, { flags: 'a' });
}

async _unwatch() {
await Promise.all([this._unwatchTail('stdout'), this._unwatchTail('stderr')]);
}

async _unwatchTail(stdxxx) {
const stdTail = `_${stdxxx}Tail`;
const logPath = this[`_${stdxxx}Path`];
const tail = this[stdTail];

if (tail) {
log.trace({ event: 'TAIL_UNWATCH' }, `unwatching ${stdxxx} log: ${logPath}`);
tail.watch = _.noop; // HACK: suppress race condition: https://github.com/lucagrulla/node-tail/blob/3791355a0ddcc5de72e1ad64ea2f0d6e78e2c9c5/src/tail.coffee#L102
tail.unwatch();
await new Promise((resolve) => setImmediate(resolve));
}

this[stdTail] = null;
}

async _closeWriteableStream() {
log.trace({ event: 'CLOSING_STREAM '}, `closing stream to: ${this._logPath}`);

const stream = this._logStream;
this._logStream = null;
await new Promise(resolve => stream.end(resolve));
}

async _createTail(file, prefix) {
if (!fs.existsSync(file)) {
log.warn({ event: 'LOG_MISSING' }, `simulator ${prefix} log is missing at path: ${file}`);
return null;
}

log.trace({ event: 'TAIL_CREATE' }, `starting to watch ${prefix} log: ${file}`);

const tail = new Tail(file, { fromBeginning: this._readFromBeginning })
.on('line', (line) => { this._appendLine(prefix, line); })
.on('error', (err) => { log.warn({ event: 'TAIL_ERROR' }, err); });

return tail;
}

_appendLine(prefix, line) {
if (this._logStream) {
this._logStream.write(`${prefix}: ${line}\n`);
} else {
log.warn({ event: 'LOG_WRITE_ERROR' }, 'failed to add line to log:\n' + line);
}
async _getProcessImagePath() {
return this._bundleId
? this._appleSimUtils.getAppContainer(this._udid, this._bundleId)
: '';
}
}

Expand Down
Loading

0 comments on commit f7d08f5

Please sign in to comment.