From afdc846a8b956912eb203dcda72753ae87be8dbc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Daniel=20B=C3=BCchele?= Date: Fri, 31 Aug 2018 10:02:51 -0700 Subject: [PATCH] log listener Summary: The logs plugin opened a new log connection every time it was activated and never closed the connection. This is now changed. Once a device is connected, a log connection is opened. The logs plugin subscribes and unsubscribes to this connection. This allows the logs plugin it even access the logs from when it was not activated and ensures to only open on connection to read the logs. Logs are persisted when switching away from the plugin. Also removes the spinner from the logs plugin, as it loads much faster now. Reviewed By: jknoxville Differential Revision: D9613054 fbshipit-source-id: e37ea56c563450e7fc4e3c85a015292be1f2dbfc --- src/PluginContainer.js | 23 ++- src/device-plugins/logs/index.js | 305 +++++++++++++++---------------- src/devices/AndroidDevice.js | 72 ++++---- src/devices/BaseDevice.js | 21 ++- src/devices/IOSDevice.js | 16 +- src/devices/OculusDevice.js | 42 ++--- src/devices/WindowsDevice.js | 3 - 7 files changed, 245 insertions(+), 237 deletions(-) diff --git a/src/PluginContainer.js b/src/PluginContainer.js index ddc799917..a683a6e00 100644 --- a/src/PluginContainer.js +++ b/src/PluginContainer.js @@ -8,6 +8,7 @@ import type {SonarPlugin, SonarBasePlugin} from './plugin.js'; import type LogManager from './fb-stubs/Logger'; import type Client from './Client.js'; import type BaseDevice from './devices/BaseDevice.js'; +import type {Props as PluginProps} from './plugin'; import {SonarDevicePlugin} from './plugin.js'; import { @@ -43,7 +44,9 @@ type Props = { selectedDevice: BaseDevice, selectedPlugin: ?string, selectedApp: ?string, - pluginStates: Object, + pluginStates: { + [pluginKey: string]: Object, + }, clients: Array, setPluginState: (payload: { pluginKey: string, @@ -128,6 +131,15 @@ class PluginContainer extends Component { return null; } + const props: PluginProps = { + key: pluginKey, + logger: this.props.logger, + persistedState: pluginStates[pluginKey] || {}, + setPersistedState: state => setPluginState({pluginKey, state}), + target, + ref: this.refChanged, + }; + return ( @@ -136,14 +148,7 @@ class PluginContainer extends Component { activePlugin.title }" encountered an error during render`} logger={this.props.logger}> - {React.createElement(activePlugin, { - key: pluginKey, - logger: this.props.logger, - persistedState: pluginStates[pluginKey] || {}, - setPersistedState: state => setPluginState({pluginKey, state}), - target, - ref: this.refChanged, - })} + {React.createElement(activePlugin, props)} diff --git a/src/device-plugins/logs/index.js b/src/device-plugins/logs/index.js index c52ec0bf4..d7cc098fb 100644 --- a/src/device-plugins/logs/index.js +++ b/src/device-plugins/logs/index.js @@ -13,14 +13,13 @@ import type { } from 'sonar'; import type {Counter} from './LogWatcher.js'; import type {DeviceLogEntry} from '../../devices/BaseDevice.js'; +import type {Props as PluginProps} from '../../plugin'; import { Text, ManagedTable, Button, colors, - FlexCenter, - LoadingIndicator, ContextMenu, FlexColumn, Glyph, @@ -39,8 +38,7 @@ type Entries = Array<{ entry: DeviceLogEntry, }>; -type LogsState = {| - initialising: boolean, +type State = {| rows: Array, entries: Entries, key2entry: {[key: string]: DeviceLogEntry}, @@ -48,6 +46,10 @@ type LogsState = {| counters: Array, |}; +type Actions = {||}; + +type PersistedState = {||}; + const Icon = styled(Glyph)({ marginTop: 5, }); @@ -234,7 +236,11 @@ function pad(chunk: mixed, len: number): string { return str; } -export default class LogTable extends SonarDevicePlugin { +export default class LogTable extends SonarDevicePlugin< + State, + Actions, + PersistedState, +> { static id = 'DeviceLogs'; static title = 'Logs'; static icon = 'arrow-right'; @@ -267,7 +273,6 @@ export default class LogTable extends SonarDevicePlugin { rows: [], entries: [], key2entry: {}, - initialising: true, highlightedRows: [], counters: this.restoreSavedCounters(), }; @@ -276,163 +281,157 @@ export default class LogTable extends SonarDevicePlugin { columns: TableColumns; columnSizes: TableColumnSizes; columnOrder: TableColumnOrder; + logListener: ?Symbol; - init() { - let batch: Entries = []; - let queued = false; - let counter = 0; + batch: Entries = []; + queued: boolean = false; + counter: number = 0; + constructor(props: PluginProps) { + super(props); const supportedColumns = this.device.supportedColumns(); this.columns = keepKeys(COLUMNS, supportedColumns); this.columnSizes = keepKeys(COLUMN_SIZE, supportedColumns); this.columnOrder = INITIAL_COLUMN_ORDER.filter(obj => supportedColumns.includes(obj.key), ); - - this.device.addLogListener((entry: DeviceLogEntry) => { - const {icon, style} = LOG_TYPES[(entry.type: string)] || LOG_TYPES.debug; - - // clean message - const message = entry.message.trim(); - entry.type === 'error'; - - let counterUpdated = false; - const counters = this.state.counters.map(counter => { - if (message.match(counter.expression)) { - counterUpdated = true; - if (counter.notify) { - new window.Notification(`${counter.label}`, { - body: 'The watched log message appeared', - }); - } - return { - ...counter, - count: counter.count + 1, - }; - } else { - return counter; - } - }); - if (counterUpdated) { - this.setState({counters}); - } - - // build the item, it will either be batched or added straight away - const item = { - entry, - row: { - columns: { - type: { - value: icon, - }, - time: { - value: ( - - {entry.date.toTimeString().split(' ')[0] + - '.' + - pad(entry.date.getMilliseconds(), 3)} - - ), - }, - message: { - value: {message}, - }, - tag: { - value: ( - {entry.tag} - ), - isFilterable: true, - }, - pid: { - value: ( - - {String(entry.pid)} - - ), - isFilterable: true, - }, - tid: { - value: ( - - {String(entry.tid)} - - ), - isFilterable: true, - }, - app: { - value: ( - {entry.app} - ), - isFilterable: true, - }, - }, - height: getLineCount(message) * 15 + 10, // 15px per line height + 8px padding - style, - type: entry.type, - filterValue: entry.message, - key: String(counter++), - }, - }; - - // batch up logs to be processed every 250ms, if we have lots of log - // messages coming in, then calling an setState 200+ times is actually - // pretty expensive - batch.push(item); - - if (!queued) { - queued = true; - - this.batchTimer = setTimeout(() => { - const thisBatch = batch; - batch = []; - queued = false; - - // update rows/entries - this.setState(state => { - const rows = [...state.rows]; - const entries = [...state.entries]; - const key2entry = {...state.key2entry}; - - for (let i = 0; i < thisBatch.length; i++) { - const {entry, row} = thisBatch[i]; - entries.push({row, entry}); - key2entry[row.key] = entry; - - let previousEntry: ?DeviceLogEntry = null; - - if (i > 0) { - previousEntry = thisBatch[i - 1].entry; - } else if (state.rows.length > 0 && state.entries.length > 0) { - previousEntry = state.entries[state.entries.length - 1].entry; - } - - this.addRowIfNeeded(rows, row, entry, previousEntry); - } - - return { - entries, - rows, - key2entry, - }; - }); - }, 100); - } - }); - - this.initTimer = setTimeout(() => { - this.setState({ - initialising: false, - }); - }, 2000); + this.logListener = this.device.addLogListener(this.processEntry); } - componentWillUnmount() { - if (this.initTimer) { - clearTimeout(this.initTimer); + processEntry = (entry: DeviceLogEntry) => { + const {icon, style} = LOG_TYPES[(entry.type: string)] || LOG_TYPES.debug; + + // clean message + const message = entry.message.trim(); + entry.type === 'error'; + + let counterUpdated = false; + const counters = this.state.counters.map(counter => { + if (message.match(counter.expression)) { + counterUpdated = true; + if (counter.notify) { + new window.Notification(`${counter.label}`, { + body: 'The watched log message appeared', + }); + } + return { + ...counter, + count: counter.count + 1, + }; + } else { + return counter; + } + }); + if (counterUpdated) { + this.setState({counters}); } + + // build the item, it will either be batched or added straight away + const item = { + entry, + row: { + columns: { + type: { + value: icon, + }, + time: { + value: ( + + {entry.date.toTimeString().split(' ')[0] + + '.' + + pad(entry.date.getMilliseconds(), 3)} + + ), + }, + message: { + value: {message}, + }, + tag: { + value: {entry.tag}, + isFilterable: true, + }, + pid: { + value: ( + + {String(entry.pid)} + + ), + isFilterable: true, + }, + tid: { + value: ( + + {String(entry.tid)} + + ), + isFilterable: true, + }, + app: { + value: {entry.app}, + isFilterable: true, + }, + }, + height: getLineCount(message) * 15 + 10, // 15px per line height + 8px padding + style, + type: entry.type, + filterValue: entry.message, + key: String(this.counter++), + }, + }; + + // batch up logs to be processed every 250ms, if we have lots of log + // messages coming in, then calling an setState 200+ times is actually + // pretty expensive + this.batch.push(item); + + if (!this.queued) { + this.queued = true; + + this.batchTimer = setTimeout(() => { + const thisBatch = this.batch; + this.batch = []; + this.queued = false; + + // update rows/entries + this.setState(state => { + const rows = [...state.rows]; + const entries = [...state.entries]; + const key2entry = {...state.key2entry}; + + for (let i = 0; i < thisBatch.length; i++) { + const {entry, row} = thisBatch[i]; + entries.push({row, entry}); + key2entry[row.key] = entry; + + let previousEntry: ?DeviceLogEntry = null; + + if (i > 0) { + previousEntry = thisBatch[i - 1].entry; + } else if (state.rows.length > 0 && state.entries.length > 0) { + previousEntry = state.entries[state.entries.length - 1].entry; + } + + this.addRowIfNeeded(rows, row, entry, previousEntry); + } + + return { + entries, + rows, + key2entry, + }; + }); + }, 100); + } + }; + + componentWillUnmount() { if (this.batchTimer) { clearTimeout(this.batchTimer); } + + if (this.logListener) { + this.device.removeLogListener(this.logListener); + } } addRowIfNeeded( @@ -536,7 +535,7 @@ export default class LogTable extends SonarDevicePlugin { }); render() { - const {initialising, rows} = this.state; + const {rows} = this.state; const contextMenuItems = [ { @@ -547,11 +546,7 @@ export default class LogTable extends SonarDevicePlugin { click: this.clearLogs, }, ]; - return initialising ? ( - - - - ) : ( + return ( { + reader.on('entry', entry => { + if (this.logListeners.size > 0) { + let type = 'unknown'; + if (entry.priority === Priority.VERBOSE) { + type = 'verbose'; + } + if (entry.priority === Priority.DEBUG) { + type = 'debug'; + } + if (entry.priority === Priority.INFO) { + type = 'info'; + } + if (entry.priority === Priority.WARN) { + type = 'warn'; + } + if (entry.priority === Priority.ERROR) { + type = 'error'; + } + if (entry.priority === Priority.FATAL) { + type = 'fatal'; + } + + this.notifyLogListeners({ + tag: entry.tag, + pid: entry.pid, + tid: entry.tid, + message: entry.message, + date: entry.date, + type, + }); + } + }); + }); } supportedPlugins = [ @@ -43,41 +78,6 @@ export default class AndroidDevice extends BaseDevice { return ['date', 'pid', 'tid', 'tag', 'message', 'type', 'time']; } - addLogListener(callback: DeviceLogListener) { - this.adb.openLogcat(this.serial).then(reader => { - reader.on('entry', async entry => { - let type = 'unknown'; - if (entry.priority === Priority.VERBOSE) { - type = 'verbose'; - } - if (entry.priority === Priority.DEBUG) { - type = 'debug'; - } - if (entry.priority === Priority.INFO) { - type = 'info'; - } - if (entry.priority === Priority.WARN) { - type = 'warn'; - } - if (entry.priority === Priority.ERROR) { - type = 'error'; - } - if (entry.priority === Priority.FATAL) { - type = 'fatal'; - } - - callback({ - tag: entry.tag, - pid: entry.pid, - tid: entry.tid, - message: entry.message, - date: entry.date, - type, - }); - }); - }); - } - reverse(): Promise { if (this.deviceType === 'physical') { return this.adb diff --git a/src/devices/BaseDevice.js b/src/devices/BaseDevice.js index a601cd521..a196c22ed 100644 --- a/src/devices/BaseDevice.js +++ b/src/devices/BaseDevice.js @@ -62,6 +62,9 @@ export default class BaseDevice { // possible src of icon to display next to the device title icon: ?string; + logListeners: Map = new Map(); + logEntries: Array = []; + supportsOS(os: string) { return os.toLowerCase() === this.os.toLowerCase(); } @@ -80,8 +83,22 @@ export default class BaseDevice { throw new Error('unimplemented'); } - addLogListener(listener: DeviceLogListener) { - throw new Error('unimplemented'); + addLogListener(callback: DeviceLogListener): Symbol { + const id = Symbol(); + this.logListeners.set(id, callback); + this.logEntries.map(callback); + return id; + } + + notifyLogListeners(entry: DeviceLogEntry) { + this.logEntries.push(entry); + if (this.logListeners.size > 0) { + this.logListeners.forEach(listener => listener(entry)); + } + } + + removeLogListener(id: Symbol) { + this.logListeners.delete(id); } spawnShell(): DeviceShell { diff --git a/src/devices/IOSDevice.js b/src/devices/IOSDevice.js index b74b89b83..d61d6dfe8 100644 --- a/src/devices/IOSDevice.js +++ b/src/devices/IOSDevice.js @@ -5,12 +5,7 @@ * @format */ -import type { - DeviceType, - LogLevel, - DeviceLogEntry, - DeviceLogListener, -} from './BaseDevice.js'; +import type {DeviceType, LogLevel, DeviceLogEntry} from './BaseDevice.js'; import child_process from 'child_process'; import BaseDevice from './BaseDevice.js'; import JSONStream from 'JSONStream'; @@ -47,7 +42,7 @@ export default class IOSDevice extends BaseDevice { super(serial, deviceType, title); this.buffer = ''; - this.log = null; + this.log = this.startLogListener(); } teardown() { @@ -60,7 +55,7 @@ export default class IOSDevice extends BaseDevice { return ['date', 'pid', 'tid', 'tag', 'message', 'type', 'time']; } - addLogListener(callback: DeviceLogListener, retries: number = 3) { + startLogListener(retries: number = 3) { if (retries === 0) { console.error('Attaching iOS log listener continuously failed.'); return; @@ -102,14 +97,15 @@ export default class IOSDevice extends BaseDevice { .pipe(new StripLogPrefix()) .pipe(JSONStream.parse('*')) .on('data', (data: RawLogEntry) => { - callback(IOSDevice.parseLogEntry(data)); + const entry = IOSDevice.parseLogEntry(data); + this.notifyLogListeners(entry); }); } catch (e) { console.error('Could not parse iOS log stream.', e); // restart log stream this.log.kill(); this.log = null; - this.addLogListener(callback, retries - 1); + this.startLogListener(retries - 1); } } diff --git a/src/devices/OculusDevice.js b/src/devices/OculusDevice.js index ad549541f..6bb00ed59 100644 --- a/src/devices/OculusDevice.js +++ b/src/devices/OculusDevice.js @@ -5,11 +5,7 @@ * @format */ -import type { - DeviceType, - DeviceLogEntry, - DeviceLogListener, -} from './BaseDevice.js'; +import type {DeviceType, DeviceLogEntry} from './BaseDevice.js'; import fs from 'fs-extra'; import os from 'os'; @@ -40,6 +36,8 @@ export default class OculusDevice extends BaseDevice { this.watcher = null; this.processedFileMap = {}; + + this.setupListener(); } teardown() { @@ -69,63 +67,63 @@ export default class OculusDevice extends BaseDevice { } } - processText(text: Buffer, callback: DeviceLogListener) { + processText(text: Buffer) { text .toString() .split('\r\n') .forEach(line => { const regex = /(.*){(\S+)}\s*\[([\w :.\\]+)\](.*)/; const match = regex.exec(line); + let entry; if (match && match.length === 5) { - callback({ + entry = { tid: 0, pid: 0, date: new Date(Date.parse(match[1])), type: this.mapLogLevel(match[2]), tag: match[3], message: match[4], - }); + }; } else if (line.trim() === '') { // skip } else { - callback({ + entry = { tid: 0, pid: 0, date: new Date(), type: 'verbose', tag: 'failed-parse', message: line, - }); + }; + } + if (entry) { + this.notifyLogListeners(entry); } }); } - addLogListener = (callback: DeviceLogListener) => { - this.setupListener(callback); - }; - - async setupListener(callback: DeviceLogListener) { + async setupListener() { const files = await fs.readdir(getLogsPath()); this.watchedFile = files .filter(file => file.startsWith('Service_')) .sort() .pop(); - this.watch(callback); - this.timer = setTimeout(() => this.checkForNewLog(callback), 5000); + this.watch(); + this.timer = setTimeout(() => this.checkForNewLog(), 5000); } - watch(callback: DeviceLogListener) { + watch() { const filePath = getLogsPath(this.watchedFile); fs.watchFile(filePath, async (current, previous) => { const readLen = current.size - previous.size; const buffer = new Buffer(readLen); const fd = await fs.open(filePath, 'r'); await fs.read(fd, buffer, 0, readLen, previous.size); - this.processText(buffer, callback); + this.processText(buffer); }); } - async checkForNewLog(callback: DeviceLogListener) { + async checkForNewLog() { const files = await fs.readdir(getLogsPath()); const latestLog = files .filter(file => file.startsWith('Service_')) @@ -135,8 +133,8 @@ export default class OculusDevice extends BaseDevice { const oldFilePath = getLogsPath(this.watchedFile); fs.unwatchFile(oldFilePath); this.watchedFile = latestLog; - this.watch(callback); + this.watch(); } - this.timer = setTimeout(() => this.checkForNewLog(callback), 5000); + this.timer = setTimeout(() => this.checkForNewLog(), 5000); } } diff --git a/src/devices/WindowsDevice.js b/src/devices/WindowsDevice.js index ba1d8471e..46d031150 100644 --- a/src/devices/WindowsDevice.js +++ b/src/devices/WindowsDevice.js @@ -5,7 +5,6 @@ * @format */ -import type {DeviceLogListener} from './BaseDevice.js'; import BaseDevice from './BaseDevice.js'; export default class WindowsDevice extends BaseDevice { @@ -22,6 +21,4 @@ export default class WindowsDevice extends BaseDevice { supportedColumns(): Array { return []; } - - addLogListener(_callback: DeviceLogListener) {} }