[Logging]metrics ops logs include event loop delay histogram data (#120451) (#121145)

Co-authored-by: Christiane (Tina) Heiligers <christiane.heiligers@elastic.co>
This commit is contained in:
Kibana Machine 2021-12-13 19:17:08 -05:00 committed by GitHub
parent a820dda2fb
commit 8e39e8733e
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
3 changed files with 64 additions and 33 deletions

View file

@ -42,6 +42,7 @@ const testMetrics = {
memory: { heap: { used_in_bytes: 100 } }, memory: { heap: { used_in_bytes: 100 } },
uptime_in_millis: 1500, uptime_in_millis: 1500,
event_loop_delay: 50, event_loop_delay: 50,
event_loop_delay_histogram: { percentiles: { '50': 50, '75': 75, '95': 95, '99': 99 } },
}, },
os: { os: {
load: { load: {
@ -56,7 +57,7 @@ describe('getEcsOpsMetricsLog', () => {
it('provides correctly formatted message', () => { it('provides correctly formatted message', () => {
const result = getEcsOpsMetricsLog(createMockOpsMetrics(testMetrics)); const result = getEcsOpsMetricsLog(createMockOpsMetrics(testMetrics));
expect(result.message).toMatchInlineSnapshot( expect(result.message).toMatchInlineSnapshot(
`"memory: 100.0B uptime: 0:00:01 load: [10.00,20.00,30.00] delay: 50.000"` `"memory: 100.0B uptime: 0:00:01 load: [10.00,20.00,30.00] mean delay: 50.000 delay histogram: { 50: 50.000; 95: 95.000; 99: 99.000 }"`
); );
}); });
@ -70,6 +71,7 @@ describe('getEcsOpsMetricsLog', () => {
const missingMetrics = { const missingMetrics = {
...baseMetrics, ...baseMetrics,
process: {}, process: {},
processes: [],
os: {}, os: {},
} as unknown as OpsMetrics; } as unknown as OpsMetrics;
const logMeta = getEcsOpsMetricsLog(missingMetrics); const logMeta = getEcsOpsMetricsLog(missingMetrics);
@ -77,39 +79,41 @@ describe('getEcsOpsMetricsLog', () => {
}); });
it('provides an ECS-compatible response', () => { it('provides an ECS-compatible response', () => {
const logMeta = getEcsOpsMetricsLog(createBaseOpsMetrics()); const logMeta = getEcsOpsMetricsLog(createMockOpsMetrics(testMetrics));
expect(logMeta).toMatchInlineSnapshot(` expect(logMeta.meta).toMatchInlineSnapshot(`
Object { Object {
"message": "memory: 1.0B load: [1.00,1.00,1.00] delay: 1.000", "event": Object {
"meta": Object { "category": Array [
"event": Object { "process",
"category": Array [ "host",
"process", ],
"host", "kind": "metric",
], "type": Array [
"kind": "metric", "info",
"type": Array [ ],
"info", },
], "host": Object {
}, "os": Object {
"host": Object { "load": Object {
"os": Object { "15m": 30,
"load": Object { "1m": 10,
"15m": 1, "5m": 20,
"1m": 1,
"5m": 1,
},
}, },
}, },
"process": Object { },
"eventLoopDelay": 1, "process": Object {
"memory": Object { "eventLoopDelay": 50,
"heap": Object { "eventLoopDelayHistogram": Object {
"usedInBytes": 1, "50": 50,
}, "95": 95,
}, "99": 99,
"uptime": 0,
}, },
"memory": Object {
"heap": Object {
"usedInBytes": 100,
},
},
"uptime": 1,
}, },
} }
`); `);

View file

@ -30,10 +30,29 @@ export function getEcsOpsMetricsLog(metrics: OpsMetrics) {
// HH:mm:ss message format for backward compatibility // HH:mm:ss message format for backward compatibility
const uptimeValMsg = uptimeVal ? `uptime: ${numeral(uptimeVal).format('00:00:00')} ` : ''; const uptimeValMsg = uptimeVal ? `uptime: ${numeral(uptimeVal).format('00:00:00')} ` : '';
// Event loop delay is in ms // Event loop delay metrics are in ms
const eventLoopDelayVal = process?.event_loop_delay; const eventLoopDelayVal = process?.event_loop_delay;
const eventLoopDelayValMsg = eventLoopDelayVal const eventLoopDelayValMsg = eventLoopDelayVal
? `delay: ${numeral(process?.event_loop_delay).format('0.000')}` ? `mean delay: ${numeral(process?.event_loop_delay).format('0.000')}`
: '';
const eventLoopDelayPercentiles = process?.event_loop_delay_histogram?.percentiles;
// Extract 50th, 95th and 99th percentiles for log meta
const eventLoopDelayHistVals = eventLoopDelayPercentiles
? {
50: eventLoopDelayPercentiles[50],
95: eventLoopDelayPercentiles[95],
99: eventLoopDelayPercentiles[99],
}
: undefined;
// Format message from 50th, 95th and 99th percentiles
const eventLoopDelayHistMsg = eventLoopDelayPercentiles
? ` delay histogram: { 50: ${numeral(eventLoopDelayPercentiles['50']).format(
'0.000'
)}; 95: ${numeral(eventLoopDelayPercentiles['95']).format('0.000')}; 99: ${numeral(
eventLoopDelayPercentiles['99']
).format('0.000')} }`
: ''; : '';
const loadEntries = { const loadEntries = {
@ -65,6 +84,7 @@ export function getEcsOpsMetricsLog(metrics: OpsMetrics) {
}, },
}, },
eventLoopDelay: eventLoopDelayVal, eventLoopDelay: eventLoopDelayVal,
eventLoopDelayHistogram: eventLoopDelayHistVals,
}, },
host: { host: {
os: { os: {
@ -75,7 +95,13 @@ export function getEcsOpsMetricsLog(metrics: OpsMetrics) {
}; };
return { return {
message: `${processMemoryUsedInBytesMsg}${uptimeValMsg}${loadValsMsg}${eventLoopDelayValMsg}`, message: [
processMemoryUsedInBytesMsg,
uptimeValMsg,
loadValsMsg,
eventLoopDelayValMsg,
eventLoopDelayHistMsg,
].join(''),
meta, meta,
}; };
} }

View file

@ -203,6 +203,7 @@ describe('MetricsService', () => {
}, },
"process": Object { "process": Object {
"eventLoopDelay": undefined, "eventLoopDelay": undefined,
"eventLoopDelayHistogram": undefined,
"memory": Object { "memory": Object {
"heap": Object { "heap": Object {
"usedInBytes": undefined, "usedInBytes": undefined,