[Fleet] An internal server error occurred: ResponseError: security_exception

[mtojek]

Hi Team,

today I spotted some flakiness in system tests for elastic/integrations.

Here are some logs recorded:

�[36mkibana_1                     |�[0m {"type":"log","@timestamp":"2021-03-25T08:56:46+00:00","tags":["error","plugins","data","data","indexPatterns"],"pid":919,"message":"ResponseError: security_exception\n    at onBody (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:337:23)\n    at IncomingMessage.onEnd (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:264:11)\n    at IncomingMessage.emit (events.js:327:22)\n    at endReadableNT (internal/streams/readable.js:1327:12)\n    at processTicksAndRejections (internal/process/task_queues.js:80:21) {\n  meta: {\n    body: { error: [Object], status: 401 },\n    statusCode: 401,\n    headers: {\n      'x-opaque-id': '46ca5bea-708f-4c67-8439-4ddbc7467da4',\n      'www-authenticate': 'Basic realm=\"security\" charset=\"UTF-8\", ApiKey',\n      'content-type': 'application/json; charset=UTF-8',\n      'content-length': '463'\n    },\n    meta: {\n      context: null,\n      request: [Object],\n      name: 'elasticsearch-js',\n      connection: [Object],\n      attempts: 0,\n      aborted: false\n    }\n  },\n  isBoom: true,\n  isServer: true,\n  data: null,\n  output: {\n    statusCode: 500,\n    payload: {\n      statusCode: 500,\n      error: 'Internal Server Error',\n      message: 'An internal server error occurred'\n    },\n    headers: {}\n  },\n  [Symbol(SavedObjectsClientErrorCode)]: 'SavedObjectsClient/generalError'\n}"}
�[36mkibana_1                     |�[0m {"type":"response","@timestamp":"2021-03-25T08:56:46+00:00","tags":[],"pid":919,"method":"get","statusCode":200,"req":{"url":"/login","method":"get","headers":{"host":"127.0.0.1:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"curl/7.61.1"},"res":{"statusCode":200,"responseTime":428,"contentLength":129055},"message":"GET /login 200 428ms - 126.0KB"}
�[36mkibana_1                     |�[0m {"type":"log","@timestamp":"2021-03-25T08:56:47+00:00","tags":["error","plugins","data","data","indexPatterns"],"pid":919,"message":"ResponseError: security_exception\n    at onBody (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:337:23)\n    at IncomingMessage.onEnd (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:264:11)\n    at IncomingMessage.emit (events.js:327:22)\n    at endReadableNT (internal/streams/readable.js:1327:12)\n    at processTicksAndRejections (internal/process/task_queues.js:80:21) {\n  meta: {\n    body: { error: [Object], status: 401 },\n    statusCode: 401,\n    headers: {\n      'x-opaque-id': 'b7f90d4d-49c8-4c32-8754-cab006be77ed',\n      'www-authenticate': 'Basic realm=\"security\" charset=\"UTF-8\", ApiKey',\n      'content-type': 'application/json; charset=UTF-8',\n      'content-length': '463'\n    },\n    meta: {\n      context: null,\n      request: [Object],\n      name: 'elasticsearch-js',\n      connection: [Object],\n      attempts: 0,\n      aborted: false\n    }\n  },\n  isBoom: true,\n  isServer: true,\n  data: null,\n  output: {\n    statusCode: 500,\n    payload: {\n      statusCode: 500,\n      error: 'Internal Server Error',\n      message: 'An internal server error occurred'\n    },\n    headers: {}\n  },\n  [Symbol(SavedObjectsClientErrorCode)]: 'SavedObjectsClient/generalError'\n}"}
�[36mkibana_1                     |�[0m {"type":"response","@timestamp":"2021-03-25T08:56:47+00:00","tags":[],"pid":919,"method":"get","statusCode":200,"req":{"url":"/login","method":"get","headers":{"host":"127.0.0.1:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"curl/7.61.1"},"res":{"statusCode":200,"responseTime":39,"contentLength":129055},"message":"GET /login 200 39ms - 126.0KB"}
�[36mkibana_1                     |�[0m {"type":"log","@timestamp":"2021-03-25T08:56:47+00:00","tags":["warning","plugins","reporting"],"pid":919,"message":"Enabling the Chromium sandbox provides an additional layer of protection."}
�[36mkibana_1                     |�[0m {"type":"log","@timestamp":"2021-03-25T08:56:49+00:00","tags":["error","plugins","data","data","indexPatterns"],"pid":919,"message":"ResponseError: security_exception\n    at onBody (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:337:23)\n    at IncomingMessage.onEnd (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:264:11)\n    at IncomingMessage.emit (events.js:327:22)\n    at endReadableNT (internal/streams/readable.js:1327:12)\n    at processTicksAndRejections (internal/process/task_queues.js:80:21) {\n  meta: {\n    body: { error: [Object], status: 401 },\n    statusCode: 401,\n    headers: {\n      'x-opaque-id': '354238e7-1066-44f4-a780-e1b0552f657c',\n      'www-authenticate': 'Basic realm=\"security\" charset=\"UTF-8\", ApiKey',\n      'content-type': 'application/json; charset=UTF-8',\n      'content-length': '463'\n    },\n    meta: {\n      context: null,\n      request: [Object],\n      name: 'elasticsearch-js',\n      connection: [Object],\n      attempts: 0,\n      aborted: false\n    }\n  },\n  isBoom: true,\n  isServer: true,\n  data: null,\n  output: {\n    statusCode: 500,\n    payload: {\n      statusCode: 500,\n      error: 'Internal Server Error',\n      message: 'An internal server error occurred'\n    },\n    headers: {}\n  },\n  [Symbol(SavedObjectsClientErrorCode)]: 'SavedObjectsClient/generalError'\n}"}
�[36mkibana_1                     |�[0m {"type":"response","@timestamp":"2021-03-25T08:56:49+00:00","tags":[],"pid":919,"method":"get","statusCode":200,"req":{"url":"/login","method":"get","headers":{"host":"127.0.0.1:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"curl/7.61.1"},"res":{"statusCode":200,"responseTime":52,"contentLength":129055},"message":"GET /login 200 52ms - 126.0KB"}
�[36mkibana_1                     |�[0m {"type":"log","@timestamp":"2021-03-25T08:56:50+00:00","tags":["error","plugins","data","data","indexPatterns"],"pid":919,"message":"ResponseError: security_exception\n    at onBody (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:337:23)\n    at IncomingMessage.onEnd (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:264:11)\n    at IncomingMessage.emit (events.js:327:22)\n    at endReadableNT (internal/streams/readable.js:1327:12)\n    at processTicksAndRejections (internal/process/task_queues.js:80:21) {\n  meta: {\n    body: { error: [Object], status: 401 },\n    statusCode: 401,\n    headers: {\n      'x-opaque-id': '357d8d68-e512-4cd5-a120-75965a865113',\n      'www-authenticate': 'Basic realm=\"security\" charset=\"UTF-8\", ApiKey',\n      'content-type': 'application/json; charset=UTF-8',\n      'content-length': '463'\n    },\n    meta: {\n      context: null,\n      request: [Object],\n      name: 'elasticsearch-js',\n      connection: [Object],\n      attempts: 0,\n      aborted: false\n    }\n  },\n  isBoom: true,\n  isServer: true,\n  data: null,\n  output: {\n    statusCode: 500,\n    payload: {\n      statusCode: 500,\n      error: 'Internal Server Error',\n      message: 'An internal server error occurred'\n    },\n    headers: {}\n  },\n  [Symbol(SavedObjectsClientErrorCode)]: 'SavedObjectsClient/generalError'\n}"}
�[36mkibana_1                     |�[0m {"type":"response","@timestamp":"2021-03-25T08:56:50+00:00","tags":[],"pid":919,"method":"get","statusCode":200,"req":{"url":"/login","method":"get","headers":{"host":"127.0.0.1:5601","user-agent":"curl/7.61.1","accept":"*/*"},"remoteAddress":"127.0.0.1","userAgent":"curl/7.61.1"},"res":{"statusCode":200,"responseTime":61,"contentLength":129055},"message":"GET /login 200 61ms - 126.0KB"}

Source: https://beats-ci.elastic.co/job/Ingest-manager/job/integrations/job/PR-804/1/artifact/build/elastic-stack-dump/latest/microsoft/logs/kibana.log

In our case it happened for the Microsoft integration, but I think @andrewvc has seen it just after starting the Fleet.

[elasticmachine]

Pinging @elastic/fleet (Team:Fleet)

[ruflin]

I've seem something similar and had a quick conversation about it with @nchaulet . It looks a bit like we have an Elastic Agent trying to connect to Kibana with an invalid API Key. I wonder if this is related to some changes we made recently? Just an idea.

[mtojek]

Another occurrence: https://beats-ci.elastic.co/job/Ingest-manager/job/integrations/job/master/158/artifact/build/elastic-stack-dump/latest/santa/logs/kibana.log

[mtojek]

Another one: https://beats-ci.elastic.co/job/Ingest-manager/job/elastic-package/job/PR-303/11/artifact/build/elastic-stack-dump/check/logs/kibana.log

[mtojek]

This time they failed without any error in Elasticsearch:

https://beats-ci.elastic.co/job/Ingest-manager/job/integrations/job/PR-815/19/artifact/build/elastic-stack-dump/latest/o365/logs/kibana.log
https://beats-ci.elastic.co/job/Ingest-manager/job/integrations/job/PR-815/19/artifact/build/elastic-stack-dump/latest/o365/logs/elasticsearch.log
https://beats-ci.elastic.co/job/Ingest-manager/job/integrations/job/PR-815/19/artifact/build/elastic-stack-dump/latest/o365/logs/elastic-agent.log

it's pretty common now: https://beats-ci.elastic.co/blue/organizations/jenkins/Ingest-manager%2Fintegrations/detail/PR-815/19/pipeline/363

[ph]

@nchaulet or @jen-huang any ideas on this one?

[nchaulet]

Not sure what happens, if licencing and security is not available for sure Fleet setup will fail, but not sure what caused this

[fearful-symmetry]

So, here's an agent-side error I see everywhere:

Could not communicate with Checking API will retry, error: fail to checkin to fleet: Post "http://kibana:5601/api/fleet/agents/f2037827-777e-4f59-8ebb-02fcfcb94982/checkin?": invalid api key to authenticate with fleet

The checkin? makes me wonder if some chunk of the URL is missing?

[mtojek]

Not sure what happens, if licencing and security is not available for sure Fleet setup will fail, but not sure what caused this

Well, if it's a possible state, then maybe we need some kind of retry mechanism? so the fleet will be setup again in a couple of seconds?

EDIT:

I heard from @ruflin that there are some works around tweaking the default fleet user.

[mtojek]

It looks like the error is thrown when unauthorized user hits kibana's /login endpoint. Actually it's 401 from Elasticsearch:

...T....POST /_security/user/_has_privileges HTTP/1.1
user-agent: elasticsearch-js/7.13.0-canary.1 (linux 4.9.184-linuxkit-x64; Node.js v14.16.0)
x-elastic-product-origin: kibana
x-opaque-id: 06c51752-2a66-432d-a8fc-2515a8fe8df6
x-elastic-client-meta: es=7.13.0p,js=14.16.0,t=7.13.0p,hc=14.16.0
content-type: application/json
content-length: 183
Host: elasticsearch:9200
Connection: keep-alive

{"index":[],"application":[{"application":"kibana-.kibana","resources":["space:default"],"privileges":["version:7.13.0-SNAPSHOT","login:","saved_object:7.13.0-SNAPSHOT:config/get"]}]}
10:25:56.980793 IP (tos 0x0, ttl 64, id 29513, offset 0, flags [DF], proto TCP (6), length 747)
    8c176c71a033.wap-wsp > elastic-package-stack_kibana_1.elastic-package-stack_default.33320: Flags [P.], cksum 0x5b1f (incorrect -> 0x8073), seq 4171:4866, ack 4061, win 381, options [nop,nop,TS val 112067924 ecr 112067924], length 695
E...sI@[email protected].........#..(Y%w..O0....}[......
...T...THTTP/1.1 401 Unauthorized
X-Opaque-Id: 06c51752-2a66-432d-a8fc-2515a8fe8df6
WWW-Authenticate: Basic realm="security" charset="UTF-8"
WWW-Authenticate: ApiKey
content-type: application/json; charset=UTF-8
content-length: 463

{"error":{"root_cause":[{"type":"security_exception","reason":"missing authentication credentials for REST request [/_security/user/_has_privileges]","header":{"WWW-Authenticate":["Basic realm=\"security\" charset=\"UTF-8\"","ApiKey"]}}],"type":"security_exception","reason":"missing authentication credentials for REST request [/_security/user/_has_privileges]","header":{"WWW-Authenticate":["Basic realm=\"security\" charset=\"UTF-8\"","ApiKey"]}},"status":401}

In Kibana 7.13.0-SNAPSHOT:

{"type":"log","@timestamp":"2021-04-02T10:25:56+00:00","tags":["error","plugins","data","data","indexPatterns"],"pid":910,"message":"ResponseError: security_exception
    at onBody (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:337:23)
    at IncomingMessage.onEnd (/usr/share/kibana/node_modules/@elastic/elasticsearch/lib/Transport.js:264:11)
    at IncomingMessage.emit (events.js:327:22)
    at endReadableNT (internal/streams/readable.js:1327:12)
    at processTicksAndRejections (internal/process/task_queues.js:80:21) {
  meta: {
    body: { error: [Object], status: 401 },
    statusCode: 401,
    headers: {
      'x-opaque-id': '06c51752-2a66-432d-a8fc-2515a8fe8df6',
      'www-authenticate': 'Basic realm=\"security\" charset=\"UTF-8\", ApiKey',
      'content-type': 'application/json; charset=UTF-8',
      'content-length': '463'
    },
    meta: {
      context: null,
      request: [Object],
      name: 'elasticsearch-js',
      connection: [Object],
      attempts: 0,
      aborted: false
    }
  },
  isBoom: true,
  isServer: true,
  data: null,
  output: {
    statusCode: 500,
    payload: {
      statusCode: 500,
      error: 'Internal Server Error',
      message: 'An internal server error occurred'
    },
    headers: {}
  },
  [Symbol(SavedObjectsClientErrorCode)]: 'SavedObjectsClient/generalError'
}"}

[mtojek]

It seems to be a duplicate of #95094 . Does it look familiar, @mattkime?