LogBox - remove ignored logs as perf improvement

Summary:
This diff improves LogBox performance by not storing and updating logs that are ignored.

Previous we stored all logs, including ignored, as a set. This was so that later, when we show a list of all logs, we would be able to show the ignored logs as well if toggled on. We stored the logs as:

```
const logs = new Set([
  {
    message: "Not ignored",
    ignored: false,
  },
  {
    message: "Ignored",
    ignored: true,
  },
  // 100s more ignored logs
]);
```

But it turns out, we can have hundreds of ignored logs within seconds in some parts of the app. This means we we're re-rendering the LogBoxContainer hundreds of times with a filter on this set to filter out the ignored logs, just to change none of the content.

Now we store as:

```
const logs = new Set([
  {
    message: "Not ignored",
  },
]);
```

Later, when we want to show ignored logs, we'll store these separately.

Changelog: [Internal]

Reviewed By: cpojer

Differential Revision: D18055799

fbshipit-source-id: f5e21f66bb4ab6137d5d3908e8c03e119e3805d5
This commit is contained in:
Rick Hanlon 2019-10-22 13:59:44 -07:00 коммит произвёл Facebook Github Bot
Родитель 1801dbd333
Коммит fb8e6610e5
12 изменённых файлов: 73 добавлений и 81 удалений

Просмотреть файл

@ -25,7 +25,6 @@ class LogBoxLog {
componentStack: ComponentStack; componentStack: ComponentStack;
stack: Stack; stack: Stack;
count: number; count: number;
ignored: boolean;
symbolicated: symbolicated:
| $ReadOnly<{|error: null, stack: null, status: 'NONE'|}> | $ReadOnly<{|error: null, stack: null, status: 'NONE'|}>
| $ReadOnly<{|error: null, stack: null, status: 'PENDING'|}> | $ReadOnly<{|error: null, stack: null, status: 'PENDING'|}>
@ -41,13 +40,11 @@ class LogBoxLog {
stack: Stack, stack: Stack,
category: string, category: string,
componentStack: ComponentStack, componentStack: ComponentStack,
ignored: boolean,
) { ) {
this.message = message; this.message = message;
this.stack = stack; this.stack = stack;
this.category = category; this.category = category;
this.componentStack = componentStack; this.componentStack = componentStack;
this.ignored = ignored;
this.count = 1; this.count = 1;
} }

Просмотреть файл

@ -13,8 +13,7 @@
import LogBoxLog from './LogBoxLog'; import LogBoxLog from './LogBoxLog';
import LogBoxLogParser from './LogBoxLogParser'; import LogBoxLogParser from './LogBoxLogParser';
export type LogBoxLogs = Array<LogBoxLog>; export type LogBoxLogs = Set<LogBoxLog>;
export type LogBoxLogsStore = Set<LogBoxLog>;
export type Observer = (logs: LogBoxLogs) => void; export type Observer = (logs: LogBoxLogs) => void;
@ -26,10 +25,9 @@ export type Subscription = $ReadOnly<{|
const observers: Set<{observer: Observer}> = new Set(); const observers: Set<{observer: Observer}> = new Set();
const ignorePatterns: Set<IgnorePattern> = new Set(); const ignorePatterns: Set<IgnorePattern> = new Set();
const logs: LogBoxLogsStore = new Set(); const logs: LogBoxLogs = new Set();
let _isDisabled = false;
let updateTimeout = null; let updateTimeout = null;
let _isDisabled = false;
function isMessageIgnored(message: string): boolean { function isMessageIgnored(message: string): boolean {
for (const pattern of ignorePatterns) { for (const pattern of ignorePatterns) {
@ -46,9 +44,9 @@ function handleUpdate(): void {
if (updateTimeout == null) { if (updateTimeout == null) {
updateTimeout = setImmediate(() => { updateTimeout = setImmediate(() => {
updateTimeout = null; updateTimeout = null;
const logsArray = _isDisabled ? [] : Array.from(logs); const logsSet = _isDisabled ? new Set() : logs;
for (const {observer} of observers) { for (const {observer} of observers) {
observer(logsArray); observer(logsSet);
} }
}); });
} }
@ -68,28 +66,22 @@ export function add({
args, args,
}); });
// In most cases, the "last log" will be the "last log not ignored". // We don't want to store these logs because they trigger a
// This will result in out of order logs when we display ignored logs, // state update whenever we add them to the store, which is
// but is a reasonable compromise. // expensive to noisy logs. If we later want to display these
const lastLog = Array.from(logs) // we will store them in a different state object.
.filter(log => !log.ignored) if (isMessageIgnored(message.content)) {
.pop(); return;
}
// If the next log has the same category as the previous one // If the next log has the same category as the previous one
// then we want to roll it up into the last log in the list // then we want to roll it up into the last log in the list
// by incrementing the count (simar to how Chrome does it). // by incrementing the count (simar to how Chrome does it).
const lastLog = Array.from(logs).pop();
if (lastLog && lastLog.category === category) { if (lastLog && lastLog.category === category) {
lastLog.incrementCount(); lastLog.incrementCount();
} else { } else {
logs.add( logs.add(new LogBoxLog(message, stack, category, componentStack));
new LogBoxLog(
message,
stack,
category,
componentStack,
isMessageIgnored(message.content),
),
);
} }
handleUpdate(); handleUpdate();
@ -135,12 +127,14 @@ export function addIgnorePatterns(
for (const pattern of newPatterns) { for (const pattern of newPatterns) {
ignorePatterns.add(pattern); ignorePatterns.add(pattern);
// We need to update all of the ignore flags in the existing logs. // We need to recheck all of the existing logs.
// This allows adding an ignore pattern anywhere in the codebase. // This allows adding an ignore pattern anywhere in the codebase.
// Without this, if you ignore a pattern after the a log is created, // Without this, if you ignore a pattern after the a log is created,
// then we would always show the log. // then we would keep showing the log.
for (let log of logs) { for (let log of logs) {
log.ignored = isMessageIgnored(log.message.content); if (isMessageIgnored(log.message.content)) {
logs.delete(log);
}
} }
} }
handleUpdate(); handleUpdate();
@ -162,8 +156,8 @@ export function observe(observer: Observer): Subscription {
const subscription = {observer}; const subscription = {observer};
observers.add(subscription); observers.add(subscription);
const logsToObserve = _isDisabled ? [] : logs; const logsToObserve = _isDisabled ? new Set() : logs;
observer(Array.from(logsToObserve)); observer(logsToObserve);
return { return {
unsubscribe(): void { unsubscribe(): void {

Просмотреть файл

@ -23,7 +23,6 @@ function getLogBoxLog() {
createStack(['A', 'B', 'C']), createStack(['A', 'B', 'C']),
'Message category...', 'Message category...',
[{component: 'LogBoxLog', location: 'LogBoxLog.js:1'}], [{component: 'LogBoxLog', location: 'LogBoxLog.js:1'}],
true,
); );
} }
@ -62,7 +61,6 @@ describe('LogBoxLog', () => {
expect(log.componentStack).toEqual([ expect(log.componentStack).toEqual([
{component: 'LogBoxLog', location: 'LogBoxLog.js:1'}, {component: 'LogBoxLog', location: 'LogBoxLog.js:1'},
]); ]);
expect(log.ignored).toEqual(true);
}); });
it('increments LogBoxLog count', () => { it('increments LogBoxLog count', () => {

Просмотреть файл

@ -19,13 +19,13 @@ const LogBoxLogData = require('../LogBoxLogData');
const registry = () => { const registry = () => {
const observer = jest.fn(); const observer = jest.fn();
LogBoxLogData.observe(observer).unsubscribe(); LogBoxLogData.observe(observer).unsubscribe();
return observer.mock.calls[0][0]; return Array.from(observer.mock.calls[0][0]);
}; };
const filteredRegistry = () => { const filteredRegistry = () => {
const observer = jest.fn(); const observer = jest.fn();
LogBoxLogData.observe(observer).unsubscribe(); LogBoxLogData.observe(observer).unsubscribe();
return observer.mock.calls[0][0].filter(log => !log.ignored); return Array.from(observer.mock.calls[0][0]);
}; };
const observe = () => { const observe = () => {
@ -204,10 +204,14 @@ describe('LogBoxLogData', () => {
}); });
it('immediately updates new observers', () => { it('immediately updates new observers', () => {
const {observer} = observe(); const {observer: observerOne} = observe();
expect(observer.mock.calls.length).toBe(1); expect(observerOne.mock.calls.length).toBe(1);
expect(observer.mock.calls[0][0]).toEqual(registry());
const observerTwo = jest.fn();
LogBoxLogData.observe(observerTwo).unsubscribe();
expect(observerTwo.mock.calls.length).toBe(1);
expect(observerOne.mock.calls[0][0]).toEqual(observerTwo.mock.calls[0][0]);
}); });
it('sends batched updates asynchronously', () => { it('sends batched updates asynchronously', () => {
@ -218,14 +222,22 @@ describe('LogBoxLogData', () => {
LogBoxLogData.add({args: ['B']}); LogBoxLogData.add({args: ['B']});
jest.runAllImmediates(); jest.runAllImmediates();
expect(observer.mock.calls.length).toBe(2); expect(observer.mock.calls.length).toBe(2);
// We expect observers to recieve the same Set object in sequential updates
// so that it doesn't break memoization for components observing state.
expect(observer.mock.calls[0][0]).toBe(observer.mock.calls[1][0]);
}); });
it('stops sending updates to unsubscribed observers', () => { it('stops sending updates to unsubscribed observers', () => {
const {observer, subscription} = observe(); const {observer: observerOne, subscription} = observe();
subscription.unsubscribe(); subscription.unsubscribe();
expect(observer.mock.calls.length).toBe(1); expect(observerOne.mock.calls.length).toBe(1);
expect(observer.mock.calls[0][0]).toEqual(registry());
const observerTwo = jest.fn();
LogBoxLogData.observe(observerTwo).unsubscribe();
expect(observerTwo.mock.calls.length).toBe(1);
expect(observerOne.mock.calls[0][0]).toEqual(observerTwo.mock.calls[0][0]);
}); });
it('updates observers when a log is added or dismissed', () => { it('updates observers when a log is added or dismissed', () => {
@ -236,7 +248,7 @@ describe('LogBoxLogData', () => {
jest.runAllImmediates(); jest.runAllImmediates();
expect(observer.mock.calls.length).toBe(2); expect(observer.mock.calls.length).toBe(2);
const lastLog = observer.mock.calls[1][0][0]; const lastLog = Array.from(observer.mock.calls[1][0])[0];
LogBoxLogData.dismiss(lastLog); LogBoxLogData.dismiss(lastLog);
jest.runAllImmediates(); jest.runAllImmediates();
expect(observer.mock.calls.length).toBe(3); expect(observer.mock.calls.length).toBe(3);

Просмотреть файл

@ -28,13 +28,13 @@ type Props = $ReadOnly<{|
function LogBoxContainer(props: Props): React.Node { function LogBoxContainer(props: Props): React.Node {
const [selectedLogIndex, setSelectedLog] = React.useState(null); const [selectedLogIndex, setSelectedLog] = React.useState(null);
const filteredLogs = props.logs.filter(log => !log.ignored); const logs = Array.from(props.logs);
function getVisibleLog() { function getVisibleLog() {
// TODO: currently returns the newest log but later will need to return // TODO: currently returns the newest log but later will need to return
// the newest log of the highest level. For example, we want to show // the newest log of the highest level. For example, we want to show
// the latest error message even if there are newer warnings. // the latest error message even if there are newer warnings.
return filteredLogs[filteredLogs.length - 1]; return logs[logs.length - 1];
} }
function handleInspectorDismissAll() { function handleInspectorDismissAll() {
@ -46,12 +46,12 @@ function LogBoxContainer(props: Props): React.Node {
// was either the last log, or when the current index // was either the last log, or when the current index
// is now outside the bounds of the log array. // is now outside the bounds of the log array.
if (selectedLogIndex != null) { if (selectedLogIndex != null) {
if (props.logs.length - 1 <= 0) { if (logs.length - 1 <= 0) {
setSelectedLog(null); setSelectedLog(null);
} else if (selectedLogIndex >= props.logs.length - 1) { } else if (selectedLogIndex >= logs.length - 1) {
setSelectedLog(selectedLogIndex - 1); setSelectedLog(selectedLogIndex - 1);
} }
props.onDismiss(props.logs[selectedLogIndex]); props.onDismiss(logs[selectedLogIndex]);
} }
} }
@ -60,7 +60,7 @@ function LogBoxContainer(props: Props): React.Node {
} }
function handleRowPress(index: number) { function handleRowPress(index: number) {
setSelectedLog(filteredLogs.length - 1); setSelectedLog(logs.length - 1);
} }
if (selectedLogIndex != null) { if (selectedLogIndex != null) {
@ -70,14 +70,14 @@ function LogBoxContainer(props: Props): React.Node {
onDismiss={handleInspectorDismiss} onDismiss={handleInspectorDismiss}
onMinimize={handleInspectorMinimize} onMinimize={handleInspectorMinimize}
onChangeSelectedIndex={setSelectedLog} onChangeSelectedIndex={setSelectedLog}
logs={filteredLogs} logs={logs}
selectedIndex={selectedLogIndex} selectedIndex={selectedLogIndex}
/> />
</View> </View>
); );
} }
return filteredLogs.length === 0 ? null : ( return logs.length === 0 ? null : (
<View style={styles.list}> <View style={styles.list}>
<View style={styles.toast}> <View style={styles.toast}>
<LogBoxLogNotification <LogBoxLogNotification

Просмотреть файл

@ -22,7 +22,7 @@ describe('LogBoxContainer', () => {
<LogBoxContainer <LogBoxContainer
onDismiss={() => {}} onDismiss={() => {}}
onDismissAll={() => {}} onDismissAll={() => {}}
logs={[]} logs={new Set()}
/>, />,
); );
@ -34,7 +34,8 @@ describe('LogBoxContainer', () => {
<LogBoxContainer <LogBoxContainer
onDismiss={() => {}} onDismiss={() => {}}
onDismissAll={() => {}} onDismissAll={() => {}}
logs={[ logs={
new Set([
new LogBoxLog( new LogBoxLog(
{ {
content: 'Some kind of message', content: 'Some kind of message',
@ -43,7 +44,6 @@ describe('LogBoxContainer', () => {
[], [],
'Some kind of message', 'Some kind of message',
[], [],
false,
), ),
new LogBoxLog( new LogBoxLog(
{ {
@ -53,9 +53,9 @@ describe('LogBoxContainer', () => {
[], [],
'Some kind of message (latest)', 'Some kind of message (latest)',
[], [],
false,
), ),
]} ])
}
/>, />,
); );

Просмотреть файл

@ -25,7 +25,6 @@ const logs = [
[], [],
'Some kind of message (first)', 'Some kind of message (first)',
[], [],
false,
), ),
new LogBoxLog( new LogBoxLog(
{ {
@ -35,7 +34,6 @@ const logs = [
[], [],
'Some kind of message (second)', 'Some kind of message (second)',
[], [],
false,
), ),
]; ];

Просмотреть файл

@ -30,7 +30,6 @@ describe('LogBoxInspectorReactFrames', () => {
[], [],
'Some kind of message', 'Some kind of message',
[], [],
false,
) )
} }
/>, />,
@ -56,7 +55,6 @@ describe('LogBoxInspectorReactFrames', () => {
location: 'MyComponentFile.js:1', location: 'MyComponentFile.js:1',
}, },
], ],
false,
) )
} }
/>, />,

Просмотреть файл

@ -40,7 +40,6 @@ const log = new LogBoxLog(
], ],
'Some kind of message (latest)', 'Some kind of message (latest)',
[], [],
false,
); );
describe('LogBoxInspectorStackFrame', () => { describe('LogBoxInspectorStackFrame', () => {

Просмотреть файл

@ -24,7 +24,6 @@ const log = new LogBoxLog(
[], [],
'Some kind of message', 'Some kind of message',
[], [],
false,
); );
describe('LogBoxLogNotification', () => { describe('LogBoxLogNotification', () => {

Просмотреть файл

@ -27,7 +27,6 @@ exports[`LogBoxContainer should render the latest log 1`] = `
"category": "Some kind of message (latest)", "category": "Some kind of message (latest)",
"componentStack": Array [], "componentStack": Array [],
"count": 1, "count": 1,
"ignored": false,
"message": Object { "message": Object {
"content": "Some kind of message (latest)", "content": "Some kind of message (latest)",
"substitutions": Array [], "substitutions": Array [],

Просмотреть файл

@ -21,7 +21,6 @@ exports[`LogBoxContainer should render first log with selectedIndex 0 1`] = `
"category": "Some kind of message (first)", "category": "Some kind of message (first)",
"componentStack": Array [], "componentStack": Array [],
"count": 1, "count": 1,
"ignored": false,
"message": Object { "message": Object {
"content": "Some kind of message (first)", "content": "Some kind of message (first)",
"substitutions": Array [], "substitutions": Array [],
@ -66,7 +65,6 @@ exports[`LogBoxContainer should render second log with selectedIndex 1 1`] = `
"category": "Some kind of message (second)", "category": "Some kind of message (second)",
"componentStack": Array [], "componentStack": Array [],
"count": 1, "count": 1,
"ignored": false,
"message": Object { "message": Object {
"content": "Some kind of message (second)", "content": "Some kind of message (second)",
"substitutions": Array [], "substitutions": Array [],