Report process cpu/memory usage in debug log

This commit is contained in:
Fedor Indutny 2022-05-09 18:12:04 -07:00 committed by GitHub
parent 8f675cdc16
commit 1b052ad16b
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
7 changed files with 80 additions and 67 deletions

View file

@ -39,6 +39,7 @@ const getHeader = (
capabilities,
remoteConfig,
statistics,
appMetrics,
user,
}: Omit<FetchLogIpcData, 'logEntries'>,
nodeVersion: string,
@ -56,6 +57,29 @@ const getHeader = (
headerSection('User info', user),
headerSection('Capabilities', capabilities),
headerSection('Remote config', remoteConfig),
headerSection(
'Metrics',
appMetrics.reduce((acc, stats, index) => {
const {
type = '?',
serviceName = '?',
name = '?',
cpu,
memory,
} = stats;
const processId = `${index}:${type}/${serviceName}/${name}`;
return {
...acc,
[processId]:
`cpuUsage=${cpu.percentCPUUsage.toFixed(2)} ` +
`wakeups=${cpu.idleWakeupsPerSecond} ` +
`workingMemory=${memory.workingSetSize} ` +
`peakWorkingMemory=${memory.peakWorkingSetSize}`,
};
}, {})
),
headerSection('Statistics', statistics),
headerSectionTitle('Logs'),
].join('\n');
@ -79,32 +103,27 @@ function formatLine(mightBeEntry: unknown): string {
return `${getLevel(entry.level)} ${entry.time} ${entry.msg}`;
}
export function fetch(
export async function fetch(
nodeVersion: string,
appVersion: string
): Promise<string> {
return new Promise(resolve => {
ipc.send('fetch-log');
const data: unknown = await ipc.invoke('fetch-log');
ipc.on('fetched-log', (_event, data: unknown) => {
let header: string;
let body: string;
if (isFetchLogIpcData(data)) {
const { logEntries } = data;
header = getHeader(data, nodeVersion, appVersion);
body = logEntries.map(formatLine).join('\n');
} else {
header = headerSectionTitle('Partial logs');
const entry: LogEntryType = {
level: LogLevel.Error,
msg: 'Invalid IPC data when fetching logs; dropping all logs',
time: new Date().toISOString(),
};
body = formatLine(entry);
}
let header: string;
let body: string;
if (isFetchLogIpcData(data)) {
const { logEntries } = data;
header = getHeader(data, nodeVersion, appVersion);
body = logEntries.map(formatLine).join('\n');
} else {
header = headerSectionTitle('Partial logs');
const entry: LogEntryType = {
level: LogLevel.Error,
msg: 'Invalid IPC data when fetching logs; dropping all logs',
time: new Date().toISOString(),
};
body = formatLine(entry);
}
const result = `${header}\n${body}`;
resolve(result);
});
});
return `${header}\n${body}`;
}

View file

@ -20,6 +20,7 @@ import rimraf from 'rimraf';
import { createStream } from 'rotating-file-stream';
import type { LoggerType } from '../types/Logging';
import * as durations from '../util/durations';
import * as log from './log';
import { Environment, getEnvironment } from '../environment';
@ -56,6 +57,13 @@ export async function initialize(
const logPath = join(basePath, 'logs');
mkdirp.sync(logPath);
let appMetrics = app.getAppMetrics();
setInterval(() => {
// CPU stats are computed since the last call to `getAppMetrics`.
appMetrics = app.getAppMetrics();
}, 30 * durations.SECOND).unref();
try {
await cleanupLogs(logPath);
} catch (error) {
@ -103,7 +111,7 @@ export async function initialize(
timestamp: pino.stdTimeFunctions.isoTime,
});
ipc.on('fetch-log', async event => {
ipc.handle('fetch-log', async () => {
const mainWindow = getMainWindow();
if (!mainWindow) {
logger.info('Logs were requested, but the main window is missing');
@ -118,6 +126,7 @@ export async function initialize(
]);
data = {
logEntries,
appMetrics,
...rest,
};
} catch (error) {
@ -125,25 +134,10 @@ export async function initialize(
return;
}
try {
event.sender.send('fetched-log', data);
} catch (err: unknown) {
// NOTE(evanhahn): We don't want to send a message to a window that's closed.
// I wanted to use `event.sender.isDestroyed()` but that seems to fail.
// Instead, we attempt the send and catch the failure as best we can.
const hasUserClosedWindow = isProbablyObjectHasBeenDestroyedError(err);
if (hasUserClosedWindow) {
logger.info('Logs were requested, but it seems the window was closed');
} else {
logger.error(
'Problem replying with fetched logs',
err instanceof Error && err.stack ? err.stack : err
);
}
}
return data;
});
ipc.on('delete-all-logs', async event => {
ipc.handle('delete-all-logs', async () => {
// Restart logging when the streams will close
shouldRestart = true;
@ -152,8 +146,6 @@ export async function initialize(
} catch (error) {
logger.error(`Problem deleting all logs: ${error.stack}`);
}
event.sender.send('delete-all-logs-complete');
});
globalLogger = logger;
@ -335,7 +327,7 @@ export function fetchLogs(logPath: string): Promise<Array<LogEntryType>> {
export const fetchAdditionalLogData = (
mainWindow: BrowserWindow
): Promise<Omit<FetchLogIpcData, 'logEntries'>> =>
): Promise<Omit<FetchLogIpcData, 'logEntries' | 'appMetrics'>> =>
new Promise(resolve => {
mainWindow.webContents.send('additional-log-data-request');
ipc.once('additional-log-data-response', (_event, data) => {
@ -352,10 +344,6 @@ function logAtLevel(level: LogLevel, ...args: ReadonlyArray<unknown>) {
}
}
function isProbablyObjectHasBeenDestroyedError(err: unknown): boolean {
return err instanceof Error && err.message === 'Object has been destroyed';
}
// This blows up using mocha --watch, so we ensure it is run just once
if (!console._log) {
log.setLogAtLevel(logAtLevel);

View file

@ -2,6 +2,7 @@
// SPDX-License-Identifier: AGPL-3.0-only
import pino from 'pino';
import type { ProcessMetric } from 'electron';
import { isRecord } from '../util/isRecord';
import { redactAll } from '../util/privacy';
import { missingCaseError } from '../util/missingCaseError';
@ -15,6 +16,7 @@ export type FetchLogIpcData = {
remoteConfig: Record<string, unknown>;
statistics: Record<string, unknown>;
user: Record<string, unknown>;
appMetrics: ReadonlyArray<ProcessMetric>;
// We expect `logEntries` to be `Array<LogEntryType>`, but we don't validate that
// upfront—we only validate it when we go to log each line. This improves the

View file

@ -2,23 +2,14 @@
// SPDX-License-Identifier: AGPL-3.0-only
import { ipcRenderer } from 'electron';
import pTimeout from 'p-timeout';
import { beforeRestart } from '../logging/set_up_renderer_logging';
import * as durations from './durations';
export function deleteAllLogs(): Promise<void> {
return new Promise((resolve, reject) => {
// Restart logging again when the file stream close
beforeRestart();
// Restart logging again when the file stream close
beforeRestart();
const timeout = setTimeout(() => {
reject(new Error('Request to delete all logs timed out'));
}, 5000);
ipcRenderer.once('delete-all-logs-complete', () => {
clearTimeout(timeout);
resolve();
});
ipcRenderer.send('delete-all-logs');
});
return pTimeout(ipcRenderer.invoke('delete-all-logs'), 5 * durations.SECOND);
}