Skip to content

Commit

Permalink
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
[Reporting] Add logging of CPU usage and memory consumption by Chromi…
Browse files Browse the repository at this point in the history
…um (elastic#99109)

* Add logging of CPU usage by chromium
* Add logging of memory consumption by chromium
* Add PDF report byte length logging
* Add PNG report byte length logging
dokmic authored and yctercero committed May 25, 2021

Unverified

This commit is not signed, but one or more authors requires that any commit attributed to them is signed.
1 parent c4ea9ac commit 4ed5b36
Showing 8 changed files with 222 additions and 43 deletions.
Original file line number Diff line number Diff line change
@@ -5,6 +5,7 @@
* 2.0.
*/

import apm from 'elastic-apm-node';
import { i18n } from '@kbn/i18n';
import del from 'del';
import fs from 'fs';
@@ -23,6 +24,7 @@ import { LevelLogger } from '../../../lib';
import { safeChildProcess } from '../../safe_child_process';
import { HeadlessChromiumDriver } from '../driver';
import { args } from './args';
import { Metrics, getMetrics } from './metrics';

type BrowserConfig = CaptureConfig['browser']['chromium'];
type ViewportConfig = CaptureConfig['viewport'];
@@ -74,6 +76,9 @@ export class HeadlessChromiumDriverFactory {

let browser: puppeteer.Browser;
let page: puppeteer.Page;
let devTools: puppeteer.CDPSession | undefined;
let startMetrics: Metrics | undefined;

try {
browser = await puppeteer.launch({
pipe: !this.browserConfig.inspect,
@@ -87,10 +92,13 @@ export class HeadlessChromiumDriverFactory {
} as puppeteer.LaunchOptions);

page = await browser.newPage();
devTools = await page.target().createCDPSession();

await devTools.send('Performance.enable', { timeDomain: 'timeTicks' });
startMetrics = await devTools.send('Performance.getMetrics');

// Log version info for debugging / maintenance
const client = await page.target().createCDPSession();
const versionInfo = await client.send('Browser.getVersion');
const versionInfo = await devTools.send('Browser.getVersion');
logger.debug(`Browser version: ${JSON.stringify(versionInfo)}`);

await page.emulateTimezone(browserTimezone);
@@ -108,6 +116,24 @@ export class HeadlessChromiumDriverFactory {

const childProcess = {
async kill() {
try {
if (devTools && startMetrics) {
const endMetrics = await devTools.send('Performance.getMetrics');
const { cpu, cpuInPercentage, memory, memoryInMegabytes } = getMetrics(
startMetrics,
endMetrics
);

apm.currentTransaction?.setLabel('cpu', cpu, false);
apm.currentTransaction?.setLabel('memory', memory, false);
logger.debug(
`Chromium consumed CPU ${cpuInPercentage}% Memory ${memoryInMegabytes}MB`
);
}
} catch (error) {
logger.error(error);
}

try {
await browser.close();
} catch (err) {
Original file line number Diff line number Diff line change
@@ -0,0 +1,67 @@
/*
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
* or more contributor license agreements. Licensed under the Elastic License
* 2.0; you may not use this file except in compliance with the Elastic License
* 2.0.
*/

jest.mock('os');

import { cpus } from 'os';
import { Metrics, getMetrics } from './metrics';

describe('getMetrics', () => {
const start = {
metrics: [
{ name: 'ProcessTime', value: 10 },
{ name: 'Timestamp', value: 1000 },
{ name: 'JSHeapTotalSize', value: 1 * 1024 * 1024 },
],
} as Metrics;
const end = {
metrics: [
{ name: 'ProcessTime', value: 110 },
{ name: 'Timestamp', value: 2000 },
{ name: 'JSHeapTotalSize', value: 5 * 1024 * 1024 },
],
} as Metrics;

beforeEach(() => {
(cpus as jest.MockedFunction<typeof cpus>).mockReturnValue([{} as any]);
});

describe('cpu', () => {
it('should evaluate CPU usage during the runtime', () => {
const { cpu } = getMetrics(start, end);

expect(cpu).toBe(0.1);
});

it('should respect a number of virtual cores available', () => {
(cpus as jest.MockedFunction<typeof cpus>).mockReturnValue([{} as any, {} as any]);
const { cpu } = getMetrics(start, end);

expect(cpu).toBe(0.05);
});

it('should return CPU usage in percentage', () => {
const { cpuInPercentage } = getMetrics(start, end);

expect(cpuInPercentage).toBe(10);
});
});

describe('memory', () => {
it('should evaluate memory consumption during the runtime', () => {
const { memory } = getMetrics(start, end);

expect(memory).toBe(5 * 1024 * 1024);
});

it('should return memory consumption in megabytes', () => {
const { memoryInMegabytes } = getMetrics(start, end);

expect(memoryInMegabytes).toBe(5);
});
});
});
Original file line number Diff line number Diff line change
@@ -0,0 +1,72 @@
/*
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
* or more contributor license agreements. Licensed under the Elastic License
* 2.0; you may not use this file except in compliance with the Elastic License
* 2.0.
*/

import type { Metrics as PuppeteerMetrics } from 'puppeteer';
import { cpus } from 'os';

declare module 'puppeteer' {
interface CDPSession {
send(command: 'Performance.getMetrics'): Promise<RawMetrics>;
}
}

type RawMetrics = Metrics;

export interface Metrics {
metrics: Metric[];
}

interface Metric {
name: keyof NormalizedMetrics;
value: unknown;
}

interface NormalizedMetrics extends Required<PuppeteerMetrics> {
ProcessTime: number;
}

interface PerformanceMetrics {
cpu: number;
cpuInPercentage: number;
memory: number;
memoryInMegabytes: number;
}

function normalizeMetrics({ metrics }: Metrics) {
return (Object.fromEntries(
metrics.map(({ name, value }) => [name, value])
) as unknown) as NormalizedMetrics;
}

function getCpuUsage(start: NormalizedMetrics, end: NormalizedMetrics) {
return (end.ProcessTime - start.ProcessTime) / (end.Timestamp - start.Timestamp) / cpus().length;
}

function toPercentage(value: number) {
return Math.round((value + Number.EPSILON) * 10000) / 100;
}

function toMegabytes(value: number) {
return Math.round((value / 1024 / 1024 + Number.EPSILON) * 100) / 100;
}

export function getMetrics(start: Metrics, end: Metrics): PerformanceMetrics {
const startMetrics = normalizeMetrics(start);
const endMetrics = normalizeMetrics(end);

const cpu = getCpuUsage(startMetrics, endMetrics);
const cpuInPercentage = toPercentage(cpu);
const { JSHeapTotalSize: memory } = endMetrics;
const memoryInMegabytes = toMegabytes(memory);

return {
cpu,
cpuInPercentage,
memory,
memoryInMegabytes,
};
}
Original file line number Diff line number Diff line change
@@ -7,7 +7,7 @@

import apm from 'elastic-apm-node';
import * as Rx from 'rxjs';
import { catchError, map, mergeMap, takeUntil } from 'rxjs/operators';
import { catchError, finalize, map, mergeMap, takeUntil } from 'rxjs/operators';
import { PNG_JOB_TYPE } from '../../../../common/constants';
import { TaskRunResult } from '../../../lib/tasks';
import { RunTaskFn, RunTaskFnFactory } from '../../../types';
@@ -51,20 +51,17 @@ export const runTaskFnFactory: RunTaskFnFactory<
job.layout
);
}),
map(({ base64, warnings }) => {
if (apmGeneratePng) apmGeneratePng.end();

return {
content_type: 'image/png',
content: base64,
size: (base64 && base64.length) || 0,
warnings,
};
}),
map(({ base64, warnings }) => ({
content_type: 'image/png',
content: base64,
size: (base64 && base64.length) || 0,
warnings,
})),
catchError((err) => {
jobLogger.error(err);
return Rx.throwError(err);
})
}),
finalize(() => apmGeneratePng?.end())
);

const stop$ = Rx.fromEventPattern(cancellationToken.on);
Original file line number Diff line number Diff line change
@@ -7,13 +7,22 @@

import apm from 'elastic-apm-node';
import * as Rx from 'rxjs';
import { map } from 'rxjs/operators';
import { finalize, map, tap } from 'rxjs/operators';
import { ReportingCore } from '../../../';
import { LevelLogger } from '../../../lib';
import { LayoutParams, PreserveLayout } from '../../../lib/layouts';
import { ScreenshotResults } from '../../../lib/screenshots';
import { ConditionalHeaders } from '../../common';

function getBase64DecodedSize(value: string) {
// @see https://en.wikipedia.org/wiki/Base64#Output_padding
return (
(value.length * 3) / 4 -
Number(value[value.length - 1] === '=') -
Number(value[value.length - 2] === '=')
);
}

export async function generatePngObservableFactory(reporting: ReportingCore) {
const getScreenshots = await reporting.getScreenshotsObservable();

@@ -33,26 +42,36 @@ export async function generatePngObservableFactory(reporting: ReportingCore) {
if (apmLayout) apmLayout.end();

const apmScreenshots = apmTrans?.startSpan('screenshots_pipeline', 'setup');
let apmBuffer: typeof apm.currentSpan;
const screenshots$ = getScreenshots({
logger,
urls: [url],
conditionalHeaders,
layout,
browserTimezone,
}).pipe(
map((results: ScreenshotResults[]) => {
if (apmScreenshots) apmScreenshots.end();
if (apmTrans) apmTrans.end();
tap(() => {
apmScreenshots?.end();
apmBuffer = apmTrans?.startSpan('get_buffer', 'output') ?? null;
}),
map((results: ScreenshotResults[]) => ({
base64: results[0].screenshots[0].base64EncodedData,
warnings: results.reduce((found, current) => {
if (current.error) {
found.push(current.error.message);
}
return found;
}, [] as string[]),
})),
tap(({ base64 }) => {
const byteLength = getBase64DecodedSize(base64);

return {
base64: results[0].screenshots[0].base64EncodedData,
warnings: results.reduce((found, current) => {
if (current.error) {
found.push(current.error.message);
}
return found;
}, [] as string[]),
};
logger.debug(`PNG buffer byte length: ${byteLength}`);
apmTrans?.setLabel('byte_length', byteLength, false);
}),
finalize(() => {
apmBuffer?.end();
apmTrans?.end();
})
);

Original file line number Diff line number Diff line change
@@ -89,7 +89,11 @@ export async function generatePdfObservableFactory(reporting: ReportingCore) {
tracker.startGetBuffer();
logger.debug(`Generating PDF Buffer...`);
buffer = await pdfOutput.getBuffer();
logger.debug(`PDF buffer byte length: ${buffer?.byteLength || 0}`);

const byteLength = buffer?.byteLength ?? 0;
logger.debug(`PDF buffer byte length: ${byteLength}`);
tracker.setByteLength(byteLength);

tracker.endGetBuffer();
} catch (err) {
logger.error(`Could not generate the PDF buffer!`);
Original file line number Diff line number Diff line change
@@ -8,6 +8,7 @@
import apm from 'elastic-apm-node';

interface PdfTracker {
setByteLength: (byteLength: number) => void;
startLayout: () => void;
endLayout: () => void;
startScreenshots: () => void;
@@ -77,6 +78,9 @@ export function getTracker(): PdfTracker {
endGetBuffer() {
if (apmGetBuffer) apmGetBuffer.end();
},
setByteLength(byteLength: number) {
apmTrans?.setLabel('byte_length', byteLength, false);
},
end() {
if (apmTrans) apmTrans.end();
},
20 changes: 5 additions & 15 deletions x-pack/plugins/reporting/server/lib/screenshots/observable.ts
Original file line number Diff line number Diff line change
@@ -7,16 +7,7 @@

import apm from 'elastic-apm-node';
import * as Rx from 'rxjs';
import {
catchError,
concatMap,
first,
mergeMap,
take,
takeUntil,
tap,
toArray,
} from 'rxjs/operators';
import { catchError, concatMap, first, mergeMap, take, takeUntil, toArray } from 'rxjs/operators';
import { HeadlessChromiumDriverFactory } from '../../browsers';
import { CaptureConfig } from '../../types';
import {
@@ -66,7 +57,9 @@ export function screenshotsObservableFactory(

return create$.pipe(
mergeMap(({ driver, exit$ }) => {
if (apmCreatePage) apmCreatePage.end();
apmCreatePage?.end();
exit$.subscribe({ error: () => apmTrans?.end() });

return Rx.from(urls).pipe(
concatMap((url, index) => {
const setup$: Rx.Observable<ScreenSetupData> = Rx.of(1).pipe(
@@ -151,10 +144,7 @@ export function screenshotsObservableFactory(
toArray()
);
}),
first(),
tap(() => {
if (apmTrans) apmTrans.end();
})
first()
);
};
}

0 comments on commit 4ed5b36

Please sign in to comment.