mirror of
https://github.com/elastic/kibana.git
synced 2025-04-23 17:28:26 -04:00
Add log entry and telemetry info about time Kibana waits for ES during startup (#180765)
## Summary This PR attempts to make it easier to quantity the time we're spending waiting on ES during Kibana startup. - Add a log entry once successfully connected to ES, surfacing the info of how much time we waited. - Add two new metric to our `kibana_started` event: - the time we spent waiting for ES - the time it took to perform the SO migration Note that for "BWC" reasons (primarily - and simplicity's sake too) we've not subtracting the time we spent from the `start` lifecycle timing we already had.
This commit is contained in:
parent
898633fc44
commit
65b1d9489a
14 changed files with 531 additions and 146 deletions
|
@ -115,6 +115,34 @@ describe('AnalyticsService', () => {
|
|||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key6": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 6",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key7": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 7",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key8": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 8",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key9": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 9",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"meta": Object {
|
||||
"_meta": Object {
|
||||
"description": "Meta data that is searchable but not aggregatable",
|
||||
|
@ -157,6 +185,34 @@ describe('AnalyticsService', () => {
|
|||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value6": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 6",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value7": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 7",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value8": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 8",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value9": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 9",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
},
|
||||
},
|
||||
]
|
||||
|
|
|
@ -94,6 +94,34 @@ describe('AnalyticsService', () => {
|
|||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key6": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 6",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key7": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 7",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key8": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 8",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"key9": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric label 9",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "keyword",
|
||||
},
|
||||
"meta": Object {
|
||||
"_meta": Object {
|
||||
"description": "Meta data that is searchable but not aggregatable",
|
||||
|
@ -136,6 +164,34 @@ describe('AnalyticsService', () => {
|
|||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value6": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 6",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value7": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 7",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value8": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 8",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
"value9": Object {
|
||||
"_meta": Object {
|
||||
"description": "Performance metric value 9",
|
||||
"optional": true,
|
||||
},
|
||||
"type": "long",
|
||||
},
|
||||
},
|
||||
},
|
||||
]
|
||||
|
|
|
@ -37,13 +37,15 @@ import { elasticsearchClientMock } from '@kbn/core-elasticsearch-client-server-m
|
|||
import { configSchema, ElasticsearchConfig } from './elasticsearch_config';
|
||||
import { ElasticsearchService, SetupDeps } from './elasticsearch_service';
|
||||
import { duration } from 'moment';
|
||||
import { isValidConnection as isValidConnectionMock } from './is_valid_connection';
|
||||
import { isValidConnection } from './is_valid_connection';
|
||||
import { pollEsNodesVersion as pollEsNodesVersionMocked } from './version_check/ensure_es_version';
|
||||
|
||||
const { pollEsNodesVersion: pollEsNodesVersionActual } = jest.requireActual(
|
||||
'./version_check/ensure_es_version'
|
||||
);
|
||||
|
||||
const isValidConnectionMock = isValidConnection as jest.Mock;
|
||||
|
||||
const delay = async (durationMs: number) =>
|
||||
await new Promise((resolve) => setTimeout(resolve, durationMs));
|
||||
|
||||
|
@ -286,6 +288,48 @@ describe('#start', () => {
|
|||
]);
|
||||
});
|
||||
|
||||
it('logs an info message about connecting to ES', async () => {
|
||||
isValidConnectionMock.mockImplementation(async () => {
|
||||
await new Promise((r) => setTimeout(r, 50));
|
||||
});
|
||||
|
||||
await elasticsearchService.setup(setupDeps);
|
||||
await elasticsearchService.start();
|
||||
|
||||
expect(isValidConnectionMock).toHaveBeenCalledTimes(1);
|
||||
|
||||
const infoMessages = loggingSystemMock.collect(coreContext.logger).info;
|
||||
expect(infoMessages).toHaveLength(1);
|
||||
|
||||
const esMessage = infoMessages[0][0];
|
||||
expect(esMessage).toMatch(
|
||||
/^Successfully connected to Elasticsearch after waiting for ([0-9]+) milliseconds$/
|
||||
);
|
||||
});
|
||||
|
||||
it('returns the information about the time spent waiting for Elasticsearch', async () => {
|
||||
isValidConnectionMock.mockImplementation(async () => {
|
||||
await new Promise((r) => setTimeout(r, 50));
|
||||
});
|
||||
|
||||
await elasticsearchService.setup(setupDeps);
|
||||
const startContract = await elasticsearchService.start();
|
||||
|
||||
expect(isValidConnectionMock).toHaveBeenCalledTimes(1);
|
||||
|
||||
const infoMessages = loggingSystemMock.collect(coreContext.logger).info;
|
||||
expect(infoMessages).toHaveLength(1);
|
||||
|
||||
const regexp =
|
||||
/^Successfully connected to Elasticsearch after waiting for ([0-9]+) milliseconds$/;
|
||||
|
||||
const esMessage = infoMessages[0][0];
|
||||
const groups = regexp.exec(esMessage);
|
||||
const esWaitTime = parseInt(groups![1], 10);
|
||||
|
||||
expect(startContract.metrics.elasticsearchWaitTime).toEqual(esWaitTime);
|
||||
});
|
||||
|
||||
describe('skipStartupConnectionCheck', () => {
|
||||
it('should validate the connection by default', async () => {
|
||||
await elasticsearchService.setup(setupDeps);
|
||||
|
|
|
@ -145,11 +145,24 @@ export class ElasticsearchService
|
|||
});
|
||||
|
||||
let capabilities: ElasticsearchCapabilities;
|
||||
let elasticsearchWaitTime: number;
|
||||
|
||||
if (!config.skipStartupConnectionCheck) {
|
||||
const elasticsearchWaitStartTime = performance.now();
|
||||
// Ensure that the connection is established and the product is valid before moving on
|
||||
await isValidConnection(this.esNodesCompatibility$);
|
||||
|
||||
elasticsearchWaitTime = Math.round(performance.now() - elasticsearchWaitStartTime);
|
||||
this.log.info(
|
||||
`Successfully connected to Elasticsearch after waiting for ${elasticsearchWaitTime} milliseconds`,
|
||||
{
|
||||
event: {
|
||||
type: 'kibana_started.elasticsearch.waitTime',
|
||||
duration: elasticsearchWaitTime,
|
||||
},
|
||||
}
|
||||
);
|
||||
|
||||
// Ensure inline scripting is enabled on the ES cluster
|
||||
const scriptingEnabled = await isInlineScriptingEnabled({
|
||||
client: this.client.asInternalUser,
|
||||
|
@ -170,12 +183,16 @@ export class ElasticsearchService
|
|||
capabilities = {
|
||||
serverless: false,
|
||||
};
|
||||
elasticsearchWaitTime = 0;
|
||||
}
|
||||
|
||||
return {
|
||||
client: this.client!,
|
||||
createClient: (type, clientConfig) => this.createClusterClient(type, config, clientConfig),
|
||||
getCapabilities: () => capabilities,
|
||||
metrics: {
|
||||
elasticsearchWaitTime,
|
||||
},
|
||||
};
|
||||
}
|
||||
|
||||
|
|
|
@ -31,7 +31,17 @@ export interface InternalElasticsearchServiceSetup extends ElasticsearchServiceS
|
|||
/**
|
||||
* @internal
|
||||
*/
|
||||
export type InternalElasticsearchServiceStart = ElasticsearchServiceStart;
|
||||
export interface InternalElasticsearchServiceStart extends ElasticsearchServiceStart {
|
||||
metrics: {
|
||||
/**
|
||||
* The number of milliseconds we had to wait until ES was ready.
|
||||
*
|
||||
* Technically, this is the amount of time spent within the `isValidConnection` check of
|
||||
* the ES service's start method.
|
||||
*/
|
||||
elasticsearchWaitTime: number;
|
||||
};
|
||||
}
|
||||
|
||||
/** @internal */
|
||||
export interface ElasticsearchStatusMeta {
|
||||
|
|
|
@ -26,6 +26,7 @@ import type {
|
|||
ElasticsearchConfig,
|
||||
ElasticsearchService,
|
||||
InternalElasticsearchServiceSetup,
|
||||
InternalElasticsearchServiceStart,
|
||||
ElasticsearchStatusMeta,
|
||||
NodesVersionCompatibility,
|
||||
ClusterInfo,
|
||||
|
@ -106,7 +107,21 @@ const createInternalSetupContractMock = () => {
|
|||
return internalSetupContract;
|
||||
};
|
||||
|
||||
const createInternalStartContractMock = createStartContractMock;
|
||||
type MockedInternalElasticsearchServiceStart = jest.Mocked<
|
||||
Omit<InternalElasticsearchServiceStart, 'client' | 'createClient'>
|
||||
> &
|
||||
Pick<MockedElasticSearchServiceStart, 'client' | 'createClient'>;
|
||||
|
||||
const createInternalStartContractMock = () => {
|
||||
const startContract = createStartContractMock();
|
||||
const internalStartContractMock: MockedInternalElasticsearchServiceStart = {
|
||||
...startContract,
|
||||
metrics: {
|
||||
elasticsearchWaitTime: 0,
|
||||
},
|
||||
};
|
||||
return internalStartContractMock;
|
||||
};
|
||||
|
||||
type ElasticsearchServiceContract = PublicMethodsOf<ElasticsearchService>;
|
||||
const createMock = () => {
|
||||
|
@ -133,6 +148,7 @@ const createCapabilities = (
|
|||
};
|
||||
|
||||
export const elasticsearchServiceMock = {
|
||||
...elasticsearchClientMock,
|
||||
create: createMock,
|
||||
createInternalPreboot: createInternalPrebootContractMock,
|
||||
createPreboot: createPrebootContractMock,
|
||||
|
@ -141,6 +157,4 @@ export const elasticsearchServiceMock = {
|
|||
createInternalStart: createInternalStartContractMock,
|
||||
createStart: createStartContractMock,
|
||||
createCapabilities,
|
||||
|
||||
...elasticsearchClientMock,
|
||||
};
|
||||
|
|
|
@ -0,0 +1,16 @@
|
|||
/*
|
||||
* 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 and the Server Side Public License, v 1; you may not use this file except
|
||||
* in compliance with, at your election, the Elastic License 2.0 or the Server
|
||||
* Side Public License, v 1.
|
||||
*/
|
||||
|
||||
import type { AnalyticsServiceSetup } from '@kbn/core-analytics-server';
|
||||
import { registerKibanaStartedEvent } from './kibana_started';
|
||||
|
||||
export { reportKibanaStartedEvent, type UptimeSteps } from './kibana_started';
|
||||
|
||||
export const registerRootEvents = (analytics: AnalyticsServiceSetup) => {
|
||||
registerKibanaStartedEvent(analytics);
|
||||
};
|
|
@ -0,0 +1,175 @@
|
|||
/*
|
||||
* 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 and the Server Side Public License, v 1; you may not use this file except
|
||||
* in compliance with, at your election, the Elastic License 2.0 or the Server
|
||||
* Side Public License, v 1.
|
||||
*/
|
||||
|
||||
import { reportPerformanceMetricEvent } from '@kbn/ebt-tools';
|
||||
import type { AnalyticsServiceSetup, AnalyticsServiceStart } from '@kbn/core-analytics-server';
|
||||
|
||||
const KIBANA_STARTED_EVENT_NAME = 'kibana_started';
|
||||
|
||||
/** @internal */
|
||||
export interface UptimePerStep {
|
||||
start: number;
|
||||
end: number;
|
||||
}
|
||||
|
||||
/** @internal */
|
||||
export interface UptimeSteps {
|
||||
constructor: UptimePerStep;
|
||||
preboot: UptimePerStep;
|
||||
setup: UptimePerStep;
|
||||
start: UptimePerStep;
|
||||
elasticsearch: {
|
||||
waitTime: number;
|
||||
};
|
||||
savedObjects: {
|
||||
migrationTime: number;
|
||||
};
|
||||
}
|
||||
|
||||
export const registerKibanaStartedEvent = (analytics: AnalyticsServiceSetup) => {
|
||||
analytics.registerEventType<{ uptime_per_step: UptimeSteps }>({
|
||||
eventType: KIBANA_STARTED_EVENT_NAME,
|
||||
schema: {
|
||||
uptime_per_step: {
|
||||
properties: {
|
||||
constructor: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until the constructor was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until the constructor finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
preboot: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until `preboot` was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until `preboot` finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
setup: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until `setup` was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until `setup` finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
start: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until `start` was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until `start` finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
elasticsearch: {
|
||||
properties: {
|
||||
waitTime: {
|
||||
type: 'long',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds Kibana waited for Elasticsearch during the its start phase',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
savedObjects: {
|
||||
properties: {
|
||||
migrationTime: {
|
||||
type: 'long',
|
||||
_meta: {
|
||||
description: 'Number of milliseconds it took to run the SO migration',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
_meta: {
|
||||
description:
|
||||
'Number of milliseconds the Node.js process has been running until each phase of the server execution is called and finished.',
|
||||
},
|
||||
},
|
||||
},
|
||||
});
|
||||
};
|
||||
|
||||
/**
|
||||
* Reports the new and legacy KIBANA_STARTED_EVENT.
|
||||
*/
|
||||
export const reportKibanaStartedEvent = ({
|
||||
analytics,
|
||||
uptimeSteps,
|
||||
}: {
|
||||
analytics: AnalyticsServiceStart;
|
||||
uptimeSteps: UptimeSteps;
|
||||
}) => {
|
||||
// Report the legacy KIBANA_STARTED_EVENT.
|
||||
analytics.reportEvent(KIBANA_STARTED_EVENT_NAME, { uptime_per_step: uptimeSteps });
|
||||
|
||||
// Report the metric-shaped KIBANA_STARTED_EVENT.
|
||||
reportPerformanceMetricEvent(analytics, {
|
||||
eventName: KIBANA_STARTED_EVENT_NAME,
|
||||
duration: uptimeSteps.start.end - uptimeSteps.constructor.start,
|
||||
key1: 'time_to_constructor',
|
||||
value1: uptimeSteps.constructor.start,
|
||||
key2: 'constructor_time',
|
||||
value2: uptimeSteps.constructor.end - uptimeSteps.constructor.start,
|
||||
key3: 'preboot_time',
|
||||
value3: uptimeSteps.preboot.end - uptimeSteps.preboot.start,
|
||||
key4: 'setup_time',
|
||||
value4: uptimeSteps.setup.end - uptimeSteps.setup.start,
|
||||
key5: 'start_time',
|
||||
value5: uptimeSteps.start.end - uptimeSteps.start.start,
|
||||
key6: 'es_wait_time',
|
||||
value6: uptimeSteps.elasticsearch.waitTime,
|
||||
key7: 'migration_time',
|
||||
value7: uptimeSteps.savedObjects.migrationTime,
|
||||
});
|
||||
};
|
|
@ -34,6 +34,8 @@ import { BehaviorSubject } from 'rxjs';
|
|||
import { REPO_ROOT } from '@kbn/repo-info';
|
||||
import { Env } from '@kbn/config';
|
||||
import { rawConfigServiceMock, getEnvOptions } from '@kbn/config-mocks';
|
||||
import { elasticsearchServiceMock } from '@kbn/core-elasticsearch-server-mocks';
|
||||
import { savedObjectsServiceMock } from '@kbn/core-saved-objects-server-mocks';
|
||||
import { Server } from './server';
|
||||
import { MIGRATION_EXCEPTION_CODE } from './constants';
|
||||
|
||||
|
@ -62,6 +64,11 @@ beforeEach(() => {
|
|||
uiPlugins: { internal: new Map(), public: new Map(), browserConfigs: new Map() },
|
||||
},
|
||||
});
|
||||
|
||||
mockElasticsearchService.start.mockResolvedValue(elasticsearchServiceMock.createInternalStart());
|
||||
mockSavedObjectsService.start.mockResolvedValue(
|
||||
savedObjectsServiceMock.createInternalStartContract()
|
||||
);
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
|
|
|
@ -8,7 +8,6 @@
|
|||
|
||||
import apm from 'elastic-apm-node';
|
||||
import { firstValueFrom } from 'rxjs';
|
||||
import { reportPerformanceMetricEvent } from '@kbn/ebt-tools';
|
||||
import type { Logger, LoggerFactory } from '@kbn/logging';
|
||||
import type { NodeRoles } from '@kbn/core-node-server';
|
||||
import { CriticalError } from '@kbn/core-base-server-internal';
|
||||
|
@ -18,7 +17,6 @@ import { LoggingService, ILoggingSystem } from '@kbn/core-logging-server-interna
|
|||
import { ensureValidConfiguration } from '@kbn/core-config-server-internal';
|
||||
import { NodeService } from '@kbn/core-node-server-internal';
|
||||
import { AnalyticsService } from '@kbn/core-analytics-server-internal';
|
||||
import type { AnalyticsServiceSetup, AnalyticsServiceStart } from '@kbn/core-analytics-server';
|
||||
import { EnvironmentService } from '@kbn/core-environment-server-internal';
|
||||
import { ExecutionContextService } from '@kbn/core-execution-context-server-internal';
|
||||
import { PrebootService } from '@kbn/core-preboot-server-internal';
|
||||
|
@ -57,23 +55,11 @@ import { SecurityService } from '@kbn/core-security-server-internal';
|
|||
import { registerServiceConfig } from './register_service_config';
|
||||
import { MIGRATION_EXCEPTION_CODE } from './constants';
|
||||
import { coreConfig, type CoreConfigType } from './core_config';
|
||||
import { registerRootEvents, reportKibanaStartedEvent, type UptimeSteps } from './events';
|
||||
|
||||
const coreId = Symbol('core');
|
||||
const KIBANA_STARTED_EVENT = 'kibana_started';
|
||||
|
||||
/** @internal */
|
||||
interface UptimePerStep {
|
||||
start: number;
|
||||
end: number;
|
||||
}
|
||||
|
||||
/** @internal */
|
||||
interface UptimeSteps {
|
||||
constructor: UptimePerStep;
|
||||
preboot: UptimePerStep;
|
||||
setup: UptimePerStep;
|
||||
start: UptimePerStep;
|
||||
}
|
||||
|
||||
export class Server {
|
||||
public readonly configService: ConfigService;
|
||||
|
@ -258,7 +244,7 @@ export class Server {
|
|||
|
||||
const analyticsSetup = this.analytics.setup();
|
||||
|
||||
this.registerKibanaStartedEventType(analyticsSetup);
|
||||
registerRootEvents(analyticsSetup);
|
||||
|
||||
const environmentSetup = this.environment.setup();
|
||||
|
||||
|
@ -391,7 +377,12 @@ export class Server {
|
|||
const securityStart = this.security.start();
|
||||
const executionContextStart = this.executionContext.start();
|
||||
const docLinkStart = this.docLinks.start();
|
||||
|
||||
const elasticsearchStart = await this.elasticsearch.start();
|
||||
this.uptimePerStep.elasticsearch = {
|
||||
waitTime: elasticsearchStart.metrics.elasticsearchWaitTime,
|
||||
};
|
||||
|
||||
const deprecationsStart = this.deprecations.start();
|
||||
const soStartSpan = startTransaction.startSpan('saved_objects.migration', 'migration');
|
||||
const savedObjectsStart = await this.savedObjects.start({
|
||||
|
@ -400,6 +391,9 @@ export class Server {
|
|||
docLinks: docLinkStart,
|
||||
node: await this.node.start(),
|
||||
});
|
||||
this.uptimePerStep.savedObjects = {
|
||||
migrationTime: savedObjectsStart.metrics.migrationDuration,
|
||||
};
|
||||
await this.resolveSavedObjectsStartPromise!(savedObjectsStart);
|
||||
|
||||
soStartSpan?.end();
|
||||
|
@ -450,7 +444,11 @@ export class Server {
|
|||
startTransaction.end();
|
||||
|
||||
this.uptimePerStep.start = { start: startStartUptime, end: performance.now() };
|
||||
this.reportKibanaStartedEvents(analyticsStart);
|
||||
|
||||
reportKibanaStartedEvent({
|
||||
uptimeSteps: this.uptimePerStep as UptimeSteps,
|
||||
analytics: analyticsStart,
|
||||
});
|
||||
|
||||
return this.coreStart;
|
||||
}
|
||||
|
@ -487,125 +485,4 @@ export class Server {
|
|||
public setupCoreConfig() {
|
||||
registerServiceConfig(this.configService);
|
||||
}
|
||||
|
||||
/**
|
||||
* Register the legacy KIBANA_STARTED_EVENT.
|
||||
* @param analyticsSetup The {@link AnalyticsServiceSetup}
|
||||
* @private
|
||||
*/
|
||||
private registerKibanaStartedEventType(analyticsSetup: AnalyticsServiceSetup) {
|
||||
analyticsSetup.registerEventType<{ uptime_per_step: UptimeSteps }>({
|
||||
eventType: KIBANA_STARTED_EVENT,
|
||||
schema: {
|
||||
uptime_per_step: {
|
||||
properties: {
|
||||
constructor: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until the constructor was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until the constructor finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
preboot: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until `preboot` was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until `preboot` finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
setup: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until `setup` was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until `setup` finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
start: {
|
||||
properties: {
|
||||
start: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until `start` was called',
|
||||
},
|
||||
},
|
||||
end: {
|
||||
type: 'float',
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until `start` finished',
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
},
|
||||
_meta: {
|
||||
description:
|
||||
'Number of seconds the Node.js process has been running until each phase of the server execution is called and finished.',
|
||||
},
|
||||
},
|
||||
},
|
||||
});
|
||||
}
|
||||
|
||||
/**
|
||||
* Reports the new and legacy KIBANA_STARTED_EVENT.
|
||||
* @param analyticsStart The {@link AnalyticsServiceStart}.
|
||||
* @private
|
||||
*/
|
||||
private reportKibanaStartedEvents(analyticsStart: AnalyticsServiceStart) {
|
||||
// Report the legacy KIBANA_STARTED_EVENT.
|
||||
analyticsStart.reportEvent(KIBANA_STARTED_EVENT, { uptime_per_step: this.uptimePerStep });
|
||||
|
||||
const ups = this.uptimePerStep;
|
||||
|
||||
// Report the metric-shaped KIBANA_STARTED_EVENT.
|
||||
reportPerformanceMetricEvent(analyticsStart, {
|
||||
eventName: KIBANA_STARTED_EVENT,
|
||||
duration: ups.start!.end - ups.constructor!.start,
|
||||
key1: 'time_to_constructor',
|
||||
value1: ups.constructor!.start,
|
||||
key2: 'constructor_time',
|
||||
value2: ups.constructor!.end - ups.constructor!.start,
|
||||
key3: 'preboot_time',
|
||||
value3: ups.preboot!.end - ups.preboot!.start,
|
||||
key4: 'setup_time',
|
||||
value4: ups.setup!.end - ups.setup!.start,
|
||||
key5: 'start_time',
|
||||
value5: ups.start!.end - ups.start!.start,
|
||||
});
|
||||
}
|
||||
}
|
||||
|
|
|
@ -601,6 +601,21 @@ describe('SavedObjectsService', () => {
|
|||
);
|
||||
});
|
||||
|
||||
it('returns the information about the time spent migrating', async () => {
|
||||
const coreContext = createCoreContext({ skipMigration: false });
|
||||
const soService = new SavedObjectsService(coreContext);
|
||||
|
||||
migratorInstanceMock.runMigrations.mockImplementation(async () => {
|
||||
await new Promise((r) => setTimeout(r, 5));
|
||||
return [];
|
||||
});
|
||||
|
||||
await soService.setup(createSetupDeps());
|
||||
const startContract = await soService.start(createStartDeps());
|
||||
|
||||
expect(startContract.metrics.migrationDuration).toBeGreaterThan(0);
|
||||
});
|
||||
|
||||
describe('#getTypeRegistry', () => {
|
||||
it('returns the internal type registry of the service', async () => {
|
||||
const coreContext = createCoreContext({ skipMigration: false });
|
||||
|
|
|
@ -76,7 +76,21 @@ export interface InternalSavedObjectsServiceSetup extends SavedObjectsServiceSet
|
|||
getTypeRegistry: () => ISavedObjectTypeRegistry;
|
||||
}
|
||||
|
||||
export type InternalSavedObjectsServiceStart = SavedObjectsServiceStart;
|
||||
/**
|
||||
* @internal
|
||||
*/
|
||||
export interface InternalSavedObjectsServiceStart extends SavedObjectsServiceStart {
|
||||
metrics: {
|
||||
/**
|
||||
* The number of milliseconds it took to run the SO migrator.
|
||||
*
|
||||
* Note: it's the time spent in the `migrator.runMigrations` call.
|
||||
* The value will be recorded even if a migration wasn't strictly performed,
|
||||
* and in that case it will just be the time spent checking if a migration was required.
|
||||
*/
|
||||
migrationDuration: number;
|
||||
};
|
||||
}
|
||||
|
||||
/** @internal */
|
||||
export interface SavedObjectsSetupDeps {
|
||||
|
@ -256,10 +270,13 @@ export class SavedObjectsService
|
|||
*/
|
||||
migrator.prepareMigrations();
|
||||
|
||||
let migrationDuration: number;
|
||||
|
||||
if (skipMigrations) {
|
||||
this.logger.warn(
|
||||
'Skipping Saved Object migrations on startup. Note: Individual documents will still be migrated when read or written.'
|
||||
);
|
||||
migrationDuration = 0;
|
||||
} else {
|
||||
this.logger.info(
|
||||
'Waiting until all Elasticsearch nodes are compatible with Kibana before starting saved objects migrations...'
|
||||
|
@ -283,7 +300,9 @@ export class SavedObjectsService
|
|||
}
|
||||
|
||||
this.logger.info('Starting saved objects migrations');
|
||||
const migrationStartTime = performance.now();
|
||||
await migrator.runMigrations();
|
||||
migrationDuration = Math.round(performance.now() - migrationStartTime);
|
||||
}
|
||||
|
||||
const createRepository = (
|
||||
|
@ -372,6 +391,9 @@ export class SavedObjectsService
|
|||
return [...indices];
|
||||
},
|
||||
getAllIndices: () => [...allIndices],
|
||||
metrics: {
|
||||
migrationDuration,
|
||||
},
|
||||
};
|
||||
}
|
||||
|
||||
|
|
|
@ -63,8 +63,12 @@ const createStartContractMock = (typeRegistry?: jest.Mocked<ISavedObjectTypeRegi
|
|||
};
|
||||
|
||||
const createInternalStartContractMock = (typeRegistry?: jest.Mocked<ISavedObjectTypeRegistry>) => {
|
||||
const internalStartContract: jest.Mocked<InternalSavedObjectsServiceStart> =
|
||||
createStartContractMock(typeRegistry);
|
||||
const internalStartContract: jest.Mocked<InternalSavedObjectsServiceStart> = {
|
||||
...createStartContractMock(typeRegistry),
|
||||
metrics: {
|
||||
migrationDuration: 0,
|
||||
},
|
||||
};
|
||||
|
||||
return internalStartContract;
|
||||
};
|
||||
|
|
|
@ -77,6 +77,46 @@ export interface PerformanceMetricEvent {
|
|||
* Value for the metric 5
|
||||
*/
|
||||
value5?: number;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Description label for the metric 6
|
||||
*/
|
||||
key6?: string;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Value for the metric 6
|
||||
*/
|
||||
value6?: number;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Description label for the metric 7
|
||||
*/
|
||||
key7?: string;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Value for the metric 7
|
||||
*/
|
||||
value7?: number;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Description label for the metric 8
|
||||
*/
|
||||
key8?: string;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Value for the metric 8
|
||||
*/
|
||||
value8?: number;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Description label for the metric 9
|
||||
*/
|
||||
key9?: string;
|
||||
/**
|
||||
* @group Free fields for custom metrics (searchable and aggregateable)
|
||||
* Value for the metric 9
|
||||
*/
|
||||
value9?: number;
|
||||
}
|
||||
|
||||
export const METRIC_EVENT_SCHEMA: RootSchema<PerformanceMetricEvent> = {
|
||||
|
@ -135,4 +175,36 @@ export const METRIC_EVENT_SCHEMA: RootSchema<PerformanceMetricEvent> = {
|
|||
type: 'long',
|
||||
_meta: { description: 'Performance metric value 5', optional: true },
|
||||
},
|
||||
key6: {
|
||||
type: 'keyword',
|
||||
_meta: { description: 'Performance metric label 6', optional: true },
|
||||
},
|
||||
value6: {
|
||||
type: 'long',
|
||||
_meta: { description: 'Performance metric value 6', optional: true },
|
||||
},
|
||||
key7: {
|
||||
type: 'keyword',
|
||||
_meta: { description: 'Performance metric label 7', optional: true },
|
||||
},
|
||||
value7: {
|
||||
type: 'long',
|
||||
_meta: { description: 'Performance metric value 7', optional: true },
|
||||
},
|
||||
key8: {
|
||||
type: 'keyword',
|
||||
_meta: { description: 'Performance metric label 8', optional: true },
|
||||
},
|
||||
value8: {
|
||||
type: 'long',
|
||||
_meta: { description: 'Performance metric value 8', optional: true },
|
||||
},
|
||||
key9: {
|
||||
type: 'keyword',
|
||||
_meta: { description: 'Performance metric label 9', optional: true },
|
||||
},
|
||||
value9: {
|
||||
type: 'long',
|
||||
_meta: { description: 'Performance metric value 9', optional: true },
|
||||
},
|
||||
};
|
||||
|
|
Loading…
Add table
Add a link
Reference in a new issue