Hi everyone,
When browsing in Kibana interface i often get disconnected with the message "SESSION_EXPIRED" and got redirected to the login page
Checking in the Kibana logs i see that right before getting disconnected the following error occurs
{
"type":"response",
"@timestamp":"2021-08-05T16:22:48+02:00",
"tags":[],
"pid":22767,
"method":"get",
"statusCode":401,
"req": {
"url":"/api/licensing/info",
"method":"get",
"headers": {
"host":"<<HOST>>:5601",
"sec-ch-ua":"\"Opera\";v=\"77\", \"Chromium\";v=\"91\", \";Not A Brand\";v=\"99\"",
"dnt":"1",
"sec-ch-ua-mobile":"?0",
"user-agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.114 Safari/537.36 OPR/77.0.4054.172",
"kbn-version":"7.13.4",
"kbn-system-request":"true",
"content-type":"application/json",
"accept":"*/*",
"sec-fetch-site":"same-origin",
"sec-fetch-mode":"cors",
"sec-fetch-dest":"empty",
"referer":"https://<<HOST>>:5601",
"accept-encoding":"gzip, deflate, br",
"accept-language":"fr-FR,fr;q=0.9,en-US;q=0.8,en;q=0.7",
"x-forwarded-for":"<<IP>>"
},
"remoteAddress":"<<REMOTE_IP>>",
"userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like
Gecko) Chrome/91.0.4472.114 Safari/537.36 OPR/77.0.4054.172",
"referer":"https://<<HOST>>:5601"
},
"res": {
"statusCode":401,
"responseTime":20,
"contentLength":66
},
"message":"GET /api/licensing/info 401 20ms - 66.0B"
}
There are 3 instances running behind a HAProxy:
Those instances runs Kibana & Elasticsearch with coordinating role
Here is the HAProxy configuration along with some defaults / options:
defaults
log global
mode tcp
option httplog
option http-keep-alive
option redispatch
option log-health-checks
timeout connect 10m
timeout client 10m
timeout server 10m
timeout http-keep-alive 10m
[...]
frontend fe_kibana
bind *:5601 ssl crt /etc/haproxy/certs no-sslv3
mode http
default_backend be_kibana
backend be_kibana
mode http
option forwardfor
option httpchk HEAD /app/kibana HTTP/1.1\r\nHost:localhost\r\nAuthorization:\ Basic\ *********************
balance roundrobin
cookie SERVERID insert indirect nocache
server es-coordinating-1 es-coordinating-1:5601 check inter 5s downinter 5s fall 1 rise 3 cookie es-coordinating-1
server es-coordinating-2 es-coordinating-2:5601 check inter 5s downinter 5s fall 1 rise 3 cookie es-coordinating-2
server es-coordinating-3 es-coordinating-3:5601 check inter 5s downinter 5s fall 1 rise 3 cookie es-coordinating-3
Obviously when the HTTP health check is getting the 401 errors, it marks the backend as down thus explaining the SESSION_EXPIRED as the enduser gets redispatched to another backend.
Aug 7 09:10:06 proxy haproxy[6445]: Server be_kibana/es-coordinating-1 is DOWN, reason: Layer7 timeout, check duration: 2002ms. 2 active and 0 backup servers left. 2 sessions active, 0 requeued, 0 remaining in queue.
Aug 7 09:10:06 proxy haproxy[6445]: Server be_kibana/es-coordinating-1 is DOWN, reason: Layer7 timeout, check duration: 2002ms. 2 active and 0 backup servers left. 2 sessions active, 0 requeued, 0 remaining in queue.
Aug 7 09:11:12 proxy haproxy[6445]: Server be_elasticsearch/es-coordinating-2 is DOWN, reason: Layer6 timeout, check duration: 2001ms. 2 active and 0 backup servers left. 1 sessions active, 0 requeued, 0 remaining in queue.
Aug 7 09:11:12 proxy haproxy[6445]: Server be_elasticsearch/es-coordinating-2 is DOWN, reason: Layer6 timeout, check duration: 2001ms. 2 active and 0 backup servers left. 1 sessions active, 0 requeued, 0 remaining in queue.
Aug 7 09:11:16 proxy haproxy[6445]: Server be_kibana/es-coordinating-2 is DOWN, reason: Layer7 timeout, check duration: 2001ms. 2 active and 0 backup servers left. 5 sessions active, 0 requeued, 0 remaining in queue.
Aug 7 09:11:16 proxy haproxy[6445]: Server be_kibana/es-coordinating-2 is DOWN, reason: Layer7 timeout, check duration: 2001ms. 2 active and 0 backup servers left. 5 sessions active, 0 requeued, 0 remaining in queue.
I found this issue License plugin · Issue #18356 · elastic/kibana · GitHub that seems to be related but i must say i got lost along reading the issue and did not get if it has been fixed or not.
I tried to query that endpoint /api/licensing/info and here is what i get:
# curl -H "Authorization: Basic *********************" -s -XGET -H 'Content-Type: application/json' "https://<<HOST>>:9200/api/licensing/info" |jq -r
{
"_index": "api",
"_type": "licensing",
"_id": "info",
"found": false
}
I don't know exactly how to interpret this API response and could not find any useful information on the internet.
That API endpoint /api/licensing/info seem to be called quite randomly by Kibana instances, sometimes i cannot event get into the interface without being logged-out and sometimes i can browse for a while before it happens again.
Cluster has been updated recently from 7.5.1 to 7.13.4, both Elasticsearch and Kibana instances.
Note that this problem was already there when it was running under 7.5.1 but was happening less often than under 7.13.4.
If it helps here is a part of Elasticsearch configuration xpack / auth related
xpack.monitoring.collection.enabled: true
xpack.monitoring.elasticsearch.collection.enabled: false
xpack.security.authc.realms.native.native1.order: 0
xpack.security.enabled: true
and finally the Kibana configuration:
elasticsearch.hosts:
- https://es-coordinating-3:9200
elasticsearch.password: *****************
elasticsearch.ssl.certificateAuthorities:
- /etc/kibana/certs/ca.pem
elasticsearch.username: kibana_system
server.port: 5601
server.host: "0.0.0.0"
kibana.index: ".kibana"
xpack.monitoring.ui.container.elasticsearch.enabled: True
I was thinking about playing with "expect" option from HAProxy healthchk possibilities but it seems to be a dirty fix.
Thank you in advance for your help.
which seem to be the root cause.