Failing test: X-Pack Accessibility Tests.x-pack/test/accessibility/apps/kibana_overview·ts - Kibana overview "before all" hook for "Kibana overview"

[kibanamachine]

A test failed on a tracked branch

Error: Request failed with status code 500
    at createError (/dev/shm/workspace/parallel/8/kibana/node_modules/axios/lib/core/createError.js:16:15)
    at settle (/dev/shm/workspace/parallel/8/kibana/node_modules/axios/lib/core/settle.js:17:12)
    at IncomingMessage.handleStreamEnd (/dev/shm/workspace/parallel/8/kibana/node_modules/axios/lib/adapters/http.js:260:11)
    at endReadableNT (internal/streams/readable.js:1327:12)
    at processTicksAndRejections (internal/process/task_queues.js:80:21) {
  config: {
    url: 'http://elastic:changeme@localhost:6181/internal/saved_objects/_migrate',
    method: 'post',
    data: '{}',
    headers: {
      Accept: 'application/json, text/plain, */*',
      'Content-Type': 'application/json;charset=utf-8',
      'kbn-xsrf': 'kbn-client',
      'User-Agent': 'axios/0.21.1',
      'Content-Length': 2
    },
    transformRequest: [ [Function: transformRequest] ],
    transformResponse: [ [Function: transformResponse] ],
    paramsSerializer: [Function: paramsSerializer],
    timeout: 0,
    adapter: [Function: httpAdapter],
    xsrfCookieName: 'XSRF-TOKEN',
    xsrfHeaderName: 'X-XSRF-TOKEN',
    maxContentLength: -1,
    maxBodyLength: -1,
    httpsAgent: null,
    validateStatus: [Function: validateStatus]
  },
  request: <ref *1> ClientRequest {
    _events: [Object: null prototype] {
      socket: [Function (anonymous)],
      abort: [Function (anonymous)],
      aborted: [Function (anonymous)],
      connect: [Function (anonymous)],
      error: [Function (anonymous)],
      timeout: [Function (anonymous)],
      prefinish: [Function: requestOnPrefinish]
    },
    _eventsCount: 7,
    _maxListeners: undefined,
    outputData: [],
    outputSize: 0,
    writable: true,
    destroyed: true,
    _last: true,
    chunkedEncoding: false,
    shouldKeepAlive: false,
    _defaultKeepAlive: true,
    useChunkedEncodingByDefault: true,
    sendDate: false,
    _removedConnection: false,
    _removedContLen: false,
    _removedTE: false,
    _contentLength: null,
    _hasBody: true,
    _trailer: '',
    finished: true,
    _headerSent: true,
    socket: Socket {
      connecting: false,
      _hadError: false,
      _parent: null,
      _host: 'localhost',
      _readableState: [ReadableState],
      _events: [Object: null prototype],
      _eventsCount: 6,
      _maxListeners: undefined,
      _writableState: [WritableState],
      allowHalfOpen: false,
      _sockname: null,
      _pendingData: null,
      _pendingEncoding: '',
      server: null,
      _server: null,
      parser: null,
      _httpMessage: [Circular *1],
      [Symbol(async_id_symbol)]: 195432,
      [Symbol(kHandle)]: null,
      [Symbol(kSetNoDelay)]: false,
      [Symbol(lastWriteQueueSize)]: 0,
      [Symbol(timeout)]: null,
      [Symbol(kBuffer)]: null,
      [Symbol(kBufferCb)]: null,
      [Symbol(kBufferGen)]: null,
      [Symbol(kCapture)]: false,
      [Symbol(kBytesRead)]: 551,
      [Symbol(kBytesWritten)]: 296,
      [Symbol(RequestTimeout)]: undefined
    },
    _header: 'POST /internal/saved_objects/_migrate HTTP/1.1\r\n' +
      'Accept: application/json, text/plain, */*\r\n' +
      'Content-Type: application/json;charset=utf-8\r\n' +
      'kbn-xsrf: kbn-client\r\n' +
      'User-Agent: axios/0.21.1\r\n' +
      'Content-Length: 2\r\n' +
      'Host: localhost:6181\r\n' +
      'Authorization: Basic ZWxhc3RpYzpjaGFuZ2VtZQ==\r\n' +
      'Connection: close\r\n' +
      '\r\n',
    _keepAliveTimeout: 0,
    _onPendingData: [Function: noopPendingOutput],
    agent: Agent {
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      defaultPort: 80,
      protocol: 'http:',
      options: [Object],
      requests: {},
      sockets: {},
      freeSockets: {},
      keepAliveMsecs: 1000,
      keepAlive: false,
      maxSockets: Infinity,
      maxFreeSockets: 256,
      scheduling: 'fifo',
      maxTotalSockets: Infinity,
      totalSocketCount: 0,
      [Symbol(kCapture)]: false
    },
    socketPath: undefined,
    method: 'POST',
    maxHeaderSize: undefined,
    insecureHTTPParser: undefined,
    path: '/internal/saved_objects/_migrate',
    _ended: true,
    res: IncomingMessage {
      _readableState: [ReadableState],
      _events: [Object: null prototype],
      _eventsCount: 3,
      _maxListeners: undefined,
      socket: [Socket],
      httpVersionMajor: 1,
      httpVersionMinor: 1,
      httpVersion: '1.1',
      complete: true,
      headers: [Object],
      rawHeaders: [Array],
      trailers: {},
      rawTrailers: [],
      aborted: false,
      upgrade: false,
      url: '',
      method: null,
      statusCode: 500,
      statusMessage: 'Internal Server Error',
      client: [Socket],
      _consuming: false,
      _dumped: false,
      req: [Circular *1],
      responseUrl: 'http://elastic:changeme@localhost:6181/internal/saved_objects/_migrate',
      redirects: [],
      [Symbol(kCapture)]: false,
      [Symbol(RequestTimeout)]: undefined
    },
    aborted: false,
    timeoutCb: null,
    upgradeOrConnect: false,
    parser: null,
    maxHeadersCount: null,
    reusedSocket: false,
    host: 'localhost',
    protocol: 'http:',
    _redirectable: Writable {
      _writableState: [WritableState],
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      _options: [Object],
      _ended: true,
      _ending: true,
      _redirectCount: 0,
      _redirects: [],
      _requestBodyLength: 2,
      _requestBodyBuffers: [],
      _onNativeResponse: [Function (anonymous)],
      _currentRequest: [Circular *1],
      _currentUrl: 'http://elastic:changeme@localhost:6181/internal/saved_objects/_migrate',
      [Symbol(kCapture)]: false
    },
    [Symbol(kCapture)]: false,
    [Symbol(kNeedDrain)]: false,
    [Symbol(corked)]: 0,
    [Symbol(kOutHeaders)]: [Object: null prototype] {
      accept: [Array],
      'content-type': [Array],
      'kbn-xsrf': [Array],
      'user-agent': [Array],
      'content-length': [Array],
      host: [Array],
      authorization: [Array]
    }
  },
  response: {
    status: 500,
    statusText: 'Internal Server Error',
    headers: {
      'x-content-type-options': 'nosniff',
      'referrer-policy': 'no-referrer-when-downgrade',
      'kbn-name': 'kibana-ci-immutable-ubuntu-18-tests-xxl-1619516906005402842',
      'kbn-license-sig': 'fb1475ad77342daa8e38108632b1ef181085e944468522e39c58d520123da339',
      'content-type': 'application/json; charset=utf-8',
      'cache-control': 'private, no-cache, no-store, must-revalidate',
      'content-length': '97',
      date: 'Tue, 27 Apr 2021 10:15:04 GMT',
      connection: 'close'
    },
    config: {
      url: 'http://elastic:changeme@localhost:6181/internal/saved_objects/_migrate',
      method: 'post',
      data: '{}',
      headers: [Object],
      transformRequest: [Array],
      transformResponse: [Array],
      paramsSerializer: [Function: paramsSerializer],
      timeout: 0,
      adapter: [Function: httpAdapter],
      xsrfCookieName: 'XSRF-TOKEN',
      xsrfHeaderName: 'X-XSRF-TOKEN',
      maxContentLength: -1,
      maxBodyLength: -1,
      httpsAgent: null,
      validateStatus: [Function: validateStatus]
    },
    request: <ref *1> ClientRequest {
      _events: [Object: null prototype],
      _eventsCount: 7,
      _maxListeners: undefined,
      outputData: [],
      outputSize: 0,
      writable: true,
      destroyed: true,
      _last: true,
      chunkedEncoding: false,
      shouldKeepAlive: false,
      _defaultKeepAlive: true,
      useChunkedEncodingByDefault: true,
      sendDate: false,
      _removedConnection: false,
      _removedContLen: false,
      _removedTE: false,
      _contentLength: null,
      _hasBody: true,
      _trailer: '',
      finished: true,
      _headerSent: true,
      socket: [Socket],
      _header: 'POST /internal/saved_objects/_migrate HTTP/1.1\r\n' +
        'Accept: application/json, text/plain, */*\r\n' +
        'Content-Type: application/json;charset=utf-8\r\n' +
        'kbn-xsrf: kbn-client\r\n' +
        'User-Agent: axios/0.21.1\r\n' +
        'Content-Length: 2\r\n' +
        'Host: localhost:6181\r\n' +
        'Authorization: Basic ZWxhc3RpYzpjaGFuZ2VtZQ==\r\n' +
        'Connection: close\r\n' +
        '\r\n',
      _keepAliveTimeout: 0,
      _onPendingData: [Function: noopPendingOutput],
      agent: [Agent],
      socketPath: undefined,
      method: 'POST',
      maxHeaderSize: undefined,
      insecureHTTPParser: undefined,
      path: '/internal/saved_objects/_migrate',
      _ended: true,
      res: [IncomingMessage],
      aborted: false,
      timeoutCb: null,
      upgradeOrConnect: false,
      parser: null,
      maxHeadersCount: null,
      reusedSocket: false,
      host: 'localhost',
      protocol: 'http:',
      _redirectable: [Writable],
      [Symbol(kCapture)]: false,
      [Symbol(kNeedDrain)]: false,
      [Symbol(corked)]: 0,
      [Symbol(kOutHeaders)]: [Object: null prototype]
    },
    data: {
      statusCode: 500,
      error: 'Internal Server Error',
      message: 'An internal server error occurred.'
    }
  },
  isAxiosError: true,
  toJSON: [Function: toJSON]
}

First failure: Jenkins Build

[elasticmachine]

Pinging @elastic/kibana-core (Team:Core)

[afharo]

It failed with a similar error to #97942

[00:00:56]             │ proc [kibana]   log   [10:15:04.729] [error][http] Error: Unable to complete saved object migrations for the [.kibana] index. Please check the health of your Elasticsearch cluster and try again. Error: [invalid_alias_name_exception]: Invalid alias name [.kibana_7.14.0], an index exists with the same name as the alias
[00:00:56]             │ proc [kibana]     at migrationStateActionMachine (/dev/shm/workspace/kibana-build-xpack-8/src/core/server/saved_objects/migrationsv2/migrations_state_action_machine.js:160:13)

[kibanamachine]

New failure: Jenkins Build

[kibanamachine]

New failure: Jenkins Build

[kibanamachine]

New failure: Jenkins Build

[mistic]

This test keeps failing and looks flaky. Skipping for now.

master/8.0: 0082e5a
7.x/7.16: f22bff7

[afharo]

Failed with similar error:

[00:01:11]             │ proc [kibana]   log   [15:14:46.855] [error][http] Error: Unable to complete saved object migrations for the [.kibana] index. Please check the health of your Elasticsearch cluster and try again. Unexpected Elasticsearch ResponseError: statusCode: 400, method: POST, url: /_aliases error: [invalid_alias_name_exception]: Invalid alias name [.kibana_7.16.0]: an index or data stream exists with the same name as the alias,
[00:01:11]             │ proc [kibana]     at migrationStateActionMachine (/dev/shm/workspace/kibana-build-20/src/core/server/saved_objects/migrationsv2/migrations_state_action_machine.js:170:13)

[afharo]

I managed to replicate it locally. It appears that a plugin is using the SO client to store something periodically. And it may trigger when esArchiver has deleted the index and the migrations are running again (but Kibana is already up!).

On top of that, the plugin is not properly handling the promise, and Kibana crashes with:

17:14:44             │ proc [kibana]   log   [15:14:43.603] [warning][environment] Detected an unhandled Promise rejection.

I noticed that one potential culprit is here:

kibana/src/plugins/kibana_usage_collection/server/collectors/event_loop_delays/track_delays.ts

Lines 43 to 55 in 634ce7f

	timer(collectionStartDelay, collectionInterval)
	.pipe(
	map((i) => (i + 1) % resetOnCount === 0),
	takeUntil(stopMonitoringEventLoop$),
	finalize(() => eventLoopDelaysCollector.stop())
	)
	.subscribe(async (shouldReset) => {
	const histogram = eventLoopDelaysCollector.collect();
	if (shouldReset) {
	eventLoopDelaysCollector.reset();
	}
	await storeHistogram(histogram, internalRepository);
	});

Apparently, .subscribe() only accepts synchronous methods, so any promise inside that may crash won't be handled.

A quick search of .subscribe(async returned 24 usages in our source code (including examples and tutorial docs 😅). We definitely need to change those usages to .pipe(mergeMap(async)).subscribe()

What do you think?

[afharo]

To catch more culprits (because of the randomness of when this happens) follow these steps:

1. Start ES yarn es snapshot
2. Start Kibana with debug logs for ES DEBUG=elasticsearch yarn start
3. Right after the migrations are complete, delete the .kibana index: DELETE http://localhost:9200/.kibana_8.0.0_001 (stopping ES may also work)
4. Wait until Kibana crashes and read the debug logs to trace the query

[bhavyarm]

fixed!

[kibanamachine]

New failure: CI Build - 7.17

[kibanamachine]

New failure: CI Build - 7.17

[pgayvallet]

Failure:

└- ✖ fail: Kibana overview "before all" hook for "Kibana overview"
--
  | │      ResponseError: illegal_argument_exception: [illegal_argument_exception] Reason: request [/.kibana_1] contains unrecognized parameter: [include_type_name]
  | │       at onBody (/opt/local-ssd/buildkite/builds/kb-n2-4-d58eeefd06e26a36/elastic/kibana-7-dot-latest-es-forward-compatibility/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:367:23)
  | │       at IncomingMessage.onEnd (/opt/local-ssd/buildkite/builds/kb-n2-4-d58eeefd06e26a36/elastic/kibana-7-dot-latest-es-forward-compatibility/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:291:11)
  | │       at IncomingMessage.emit (node:events:402:35)
  | │       at endReadableNT (node:internal/streams/readable:1343:12)
  | │       at processTicksAndRejections (node:internal/process/task_queues:83:21)
  | │
  | │
  | └-> "after all" hook for "Kibana overview"
  | └- ✖ fail: Kibana overview "after all" hook for "Kibana overview"
  | │      ResponseError: x_content_parse_exception: [parsing_exception] Reason: [1:65] [ids] unknown field [type]
  | │       at onBody (/opt/local-ssd/buildkite/builds/kb-n2-4-d58eeefd06e26a36/elastic/kibana-7-dot-latest-es-forward-compatibility/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:367:23)
  | │       at IncomingMessage.onEnd (/opt/local-ssd/buildkite/builds/kb-n2-4-d58eeefd06e26a36/elastic/kibana-7-dot-latest-es-forward-compatibility/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:291:11)
  | │       at IncomingMessage.emit (node:events:402:35)
  | │       at endReadableNT (node:internal/streams/readable:1343:12)
  | │       at processTicksAndRejections (node:internal/process/task_queues:83:21)
  | │

[bhavyarm]

Hasn't failed in a real long time. Opening a pr to remove the skipped test comment.