Losing a session in a Canvas

Dennis_Rietvink · January 22, 2020, 4:10pm

Our Kibana has a canvas screen showing the uptime of various infrastructure components. Access to the portal is attained through single sign on handled by Keycloak OIDC. When we minimize the screen or go to other tabs and go back later the session is gone. The data feed has ended and warnings are shown. If we refresh the page Keycloak is shown.

Do you know why this is happening since the session should be active for the lifetime of the browser window
How can we ensure a session is kept alive for canvasses and dashboards?
When these kind of timeouts happen how to automatically reload the page?

Larry_Gregory · January 27, 2020, 12:08pm

Hey @Dennis_Rietvink,

Just a couple of followup questions for you:

What specific version of Kibana/ES are you running?
Approximately how long does it take for you to lose your session? Minutes/Hours/Day(s)?
Does this consistently happen just within Canvas, or are there other Kibana applications where you're noticing this behavior?
Can you share your elasticsearch.yml and kibana.yml configurations, redacting any sensitive information such as keys and passwords?

It's hard to say without looking at logs, but one possible cause is the Elasticsearch Bearer Token timeout. When you authenticate to Kibana via OIDC, Kibana/ES generates a bearer token to represent your session in Kibana. This is done via the Elasticsearch Token Service.

By default, these tokens have a 20 minute lifespan, but Kibana should automatically refresh this token once it expires. Kibana has 24 hours from the time the token was generated to refresh this, so if you're leaving the tab unused in the background for longer than that, then it's possible this is the cause. If that's the case, then I'm not aware of any immediate fixes, but that's something we can investigate further if it turns out to be the problem.

Dennis_Rietvink · January 27, 2020, 1:03pm

Hi @Larry_Gregory,

Thanks for your early reply!

We are running the Elasticsearch cluster in the Elastic Cloud and the Kibana instances are hosted locally. Both are running version 7.5.1
I just timed it and it seems to happen around 20 minutes after the dashboard page has been loaded,
So far we have only seen this behavior with Canvas dashboards. The Canvas dashboard is embedded in our portal using an iframe with the following url:

https://kibana.test.**************.com/s/customer/app/canvas#/workpad/workpad-fec09cf5-f945-4a74-89f0-9dad671ba96a/page/1?__fullscreen=true&__refreshInterval=5s

elasticsearch.yml

xpack:
  security:
    authc:
      realms:
        oidc:
          customer: 
            order: 2
            rp.client_id: "kibana" 
            rp.response_type: "code"
            rp.redirect_uri: "https://kibana.test.**************.com/api/security/v1/oidc" 
            rp.post_logout_redirect_uri: "https://kibana.test.**************.com/logout"
            op.issuer: "https://keycloak.test.**************.com/auth/realms/customer" 
            op.authorization_endpoint: "https://keycloak.test.**************.com/auth/realms/customer/protocol/openid-connect/auth" 
            op.token_endpoint: "https://keycloak.test.**************.com/auth/realms/customer/protocol/openid-connect/token" 
            op.userinfo_endpoint: "https://keycloak.test.**************.com/auth/realms/customer/protocol/openid-connect/userinfo" 
            op.jwkset_path: "https://keycloak.test.**************.com/auth/realms/customer/protocol/openid-connect/certs" 
            claims.principal: sub
            claims.name: preferred_username
            claims.mail: email
            claims.groups: groups
          employees: 
            order: 2
            rp.client_id: "kibana" 
            rp.response_type: "code"
            rp.redirect_uri: "https://kibana-sp.test.**************.com/api/security/v1/oidc" 
            rp.post_logout_redirect_uri: "https://kibana-sp.test.**************.com/logout"
            op.issuer: "https://keycloak.test.**************.com/auth/realms/employees" 
            op.authorization_endpoint: "https://keycloak.test.**************.com/auth/realms/employees/protocol/openid-connect/auth" 
            op.token_endpoint: "https://keycloak.test.**************.com/auth/realms/employees/protocol/openid-connect/token" 
            op.userinfo_endpoint: "https://keycloak.test.**************.com/auth/realms/employees/protocol/openid-connect/userinfo" 
            op.jwkset_path: "https://keycloak.test.**************.com/auth/realms/employees/protocol/openid-connect/certs" 
            claims.principal: sub
            claims.name: preferred_username
            claims.mail: email
            claims.groups: groups

kibana.yml:

server.name: kibana-customer
server.host: "0.0.0.0"
xpack.security.enabled: true
logging.verbose: false
xpack.security.authc.providers: [oidc]
xpack.security.authc.oidc.realm: "customer" 
server.xsrf.whitelist: [/api/security/v1/oidc]

As a test, I manually invoked the Token Service with the following command:

POST /_security/oauth2/token
{
  "grant_type" : "client_credentials"
}

which returned:

{
  "access_token" : "16euAxZHcFd4NXZKLVFjcVA0VkFGSml5MFVR",
  "type" : "Bearer",
  "expires_in" : 1200
}

Please let me know if you need any additional information.

Best,
Dennis

Larry_Gregory · January 27, 2020, 1:58pm

Thanks for the quick followup and detailed response, this is helpful

I don't see anything out of place here. I've setup a 7.5.1 cluster on Elastic Cloud to try to follow along here, but I don't have a working OIDC setup yet.

If you're able/willing to make changes to your environment, I could use some help troubleshooting further. Since the timeout seems to happen after about 20 minutes, it feels like it could be related to the token service timeout.

While I work on getting a more robust environment setup, can you try the following:

Set logging.verbose: true in your kibana.yml, and restart Kibana
Login to Kibana, and navigate to a Canvas worksheet
Wait for the session timeout to occur again
Provide the last handful of minutes from the log file (it will log a lot of garbage, and a 20 minute verbose log file will likely be too much). We should hopefully see log entries about the token refresh procedure in there.

Dennis_Rietvink · January 27, 2020, 3:12pm

Please find below a 'heavily' cleanup log trace from load to failure:

{"type":"response","@timestamp":"2020-01-27T14:28:00Z","tags":[],"pid":6,"method":"get","statusCode":200,"req":{"url":"/login","method":"get","headers":{"host":"10.42.2.23:5601","user-agent":"kube-probe/1.15","accept-encoding":"gzip","connection":"close"},"remoteAddress":"10.102.20.196","userAgent":"10.102.20.196"},"res":{"statusCode":200,"responseTime":102,"contentLength":9},"message":"GET /login 200 102ms - 9.0B"}
{"type":"log","@timestamp":"2020-01-27T14:28:01Z","tags":["license","debug","xpack"],"pid":6,"message":"Calling [data] Elasticsearch _xpack API. Polling frequency: 30001"}
{"type":"log","@timestamp":"2020-01-27T14:28:02Z","tags":["debug","upgrade_assistant","reindex_worker"],"pid":6,"message":"Polling for reindex operations"}
{"type":"log","@timestamp":"2020-01-27T14:28:02Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate user request to /api/interpreter/fns."}
{"type":"log","@timestamp":"2020-01-27T14:28:02Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via header."}
{"type":"log","@timestamp":"2020-01-27T14:28:02Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Authorization header is not presented."}
{"type":"log","@timestamp":"2020-01-27T14:28:02Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via state."}
{"type":"log","@timestamp":"2020-01-27T14:28:02Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Request has been authenticated via state."}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate user request to /app/canvas."}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via header."}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Authorization header is not presented."}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via state."}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Request has been authenticated via state."}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["debug","plugins","spaces"],"pid":6,"message":"Verifying access to space \"customer\""}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["security","app-authorization","debug"],"pid":6,"message":"authorizing access to \"canvas\""}
{"type":"log","@timestamp":"2020-01-27T14:28:05Z","tags":["security","app-authorization","debug"],"pid":6,"message":"authorized for \"canvas\""}

{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate user request to /api/canvas/workpad/workpad-fec09cf5-f945-4a74-89f0-9dad671ba96a."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via header."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Authorization header is not presented."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via state."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate user request to /api/spaces/space."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via header."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Authorization header is not presented."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via state."}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Request has been authenticated via state."}

{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","spaces"],"pid":6,"message":"Inside GET /api/spaces/space"}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","spaces"],"pid":6,"message":"Attempting to retrieve all spaces for any purpose"}
{"type":"response","@timestamp":"2020-01-27T14:28:14Z","tags":[],"pid":6,"method":"get","statusCode":200,"req":{"url":"/api/security/v1/me","method":"get","headers":{"host":"kibana.test.*************.com","x-request-id":"4e88b8c653e3ac4081fd2b2514762a8e","x-real-ip":"***","x-forwarded-for":"***","x-forwarded-host":"kibana.test.*************.com","x-forwarded-port":"443","x-forwarded-proto":"https","x-original-uri":"/s/customer/api/security/v1/me","x-scheme":"https","x-original-forwarded-for":"***","x-amzn-trace-id":"Root=1-5e2ef37e-a93f5ce0a872a64024178de0","accept":"application/json, text/plain, */*","kbn-version":"7.5.1","user-agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.130 Safari/537.36","sec-fetch-site":"same-origin","sec-fetch-mode":"cors","referer":"https://kibana.test.*************.com/s/customer/app/canvas","accept-encoding":"gzip, deflate, br","accept-language":"en-US,en;q=0.9,nl;q=0.8,pt;q=0.7"},"remoteAddress":"10.102.20.196","userAgent":"10.102.20.196","referer":"https://kibana.test.*************.com/s/customer/app/canvas"},"res":{"statusCode":200,"responseTime":107,"contentLength":9},"message":"GET /api/security/v1/me 200 107ms - 9.0B"}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","spaces"],"pid":6,"message":"SpacesClient.getAll(), using RBAC. Found 3 spaces"}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","spaces"],"pid":6,"message":"SpacesClient.getAll(), authorized for 1 spaces, derived from ES privilege check: {\"customer\":{\"login:\":true},\"default\":{\"login:\":false},\"service-provider\":{\"login:\":false}}"}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","spaces"],"pid":6,"message":"SpacesClient.getAll(), using RBAC. returning spaces: customer"}
{"type":"log","@timestamp":"2020-01-27T14:28:14Z","tags":["debug","plugins","spaces"],"pid":6,"message":"Retrieved 1 spaces for any purpose"}

{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate user request to /api/interpreter/fns."}
{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via header."}
{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Authorization header is not presented."}
{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via state."}
{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Failed to authenticate request via state: [security_exception] token expired, with { header={ WWW-Authenticate=\"Bearer realm=\\\"security\\\", error=\\\"invalid_token\\\", error_description=\\\"The access token expired\\\"\" } }"}
{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to refresh elasticsearch access token."}
{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","tokens"],"pid":6,"message":"Access token has been successfully refreshed."}
{"type":"log","@timestamp":"2020-01-27T14:46:59Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Request has been authenticated via refreshed token."}
{"type":"response","@timestamp":"2020-01-27T14:47:00Z","tags":[],"pid":6,"method":"get","statusCode":200,"req":{"url":"/login","method":"get","headers":{"host":"10.42.2.23:5601","user-agent":"kube-probe/1.15","accept-encoding":"gzip","connection":"close"},"remoteAddress":"10.102.20.196","userAgent":"10.102.20.196"},"res":{"statusCode":200,"responseTime":105,"contentLength":9},"message":"GET /login 200 105ms - 9.0B"}
{"type":"log","@timestamp":"2020-01-27T14:47:03Z","tags":["license","debug","xpack"],"pid":6,"message":"Calling [data] Elasticsearch _xpack API. Polling frequency: 30001"}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate user request to /api/interpreter/fns."}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via header."}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Authorization header is not presented."}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to authenticate via state."}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Failed to authenticate request via state: [security_exception] token expired, with { header={ WWW-Authenticate=\"Bearer realm=\\\"security\\\", error=\\\"invalid_token\\\", error_description=\\\"The access token expired\\\"\" } }"}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","oidc"],"pid":6,"message":"Trying to refresh elasticsearch access token."}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","tokens"],"pid":6,"message":"Failed to refresh access token: invalid_grant"}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["debug","plugins","security","tokens"],"pid":6,"message":"Refresh token is either expired or already used."}
{"type":"log","@timestamp":"2020-01-27T14:47:04Z","tags":["info","plugins","security","authentication"],"pid":6,"message":"Authentication attempt failed: Both access and refresh tokens are expired."}

Larry_Gregory · January 27, 2020, 4:29pm

This is great, thanks for taking the time to collect this for me. Thanks also for cleaning up the verbose log output

Give me some time to triage this further: I'll report back as soon as I have something for you.

Larry_Gregory · January 28, 2020, 12:16pm

Alright, I'm having a hard time reproducing this unfortunately. Can I ask you to try something else? I want to see if the issue is with the OIDC auth provider specifically, with the token service, or something else entirely.

Based on the logs you attached, it appears to be related to the token service, but it's not clear yet to me what's causing the problem.

Trial 1: Token auth provider

Kibana ships with a token auth provider, which acts just like the basic auth provider, with the distinction that it uses the ES token service internally to offer stateful sessions.

This provider uses the built-in native realm in Elasticsearch, so be sure the native realm is also enabled in ES. If not already configured, you'll also want to provision a user in the native realm which can use Kibana. Let me know if you need help with this part, and I can elaborate further.

In kibana.yml:

xpack.security.authc.providers: [oidc, token]

You can omit oidc from this list if you are OK not disabling this for the duration of the trial.
If you don't omit oidc, then you'll need to activate the login form manually in order to use the token provider, by navigating to https://kibana-sp.test.**************.com/login without an existing oidc session (private browsing/incognito works well for this).

Once logged in, navigate to your canvas worksheet and see if you still experience the timeout after 20 minutes has passed.

Trial 2: Capture a HAR

To triage this further, it would be really useful for us to also get a HAR, which is an archived recording of your browser's Kibana session. The HAR can contain sensitive information (such as session cookies, and all data sent/received to Kibana), so only do this if you're comfortable and able.

I don't need the HAR showing the initial login, but if you start recording as soon as you enter Kibana, and stop soon after the timeout happens, that would be fantastic.

If you haven't done this before, I have instructions here.

As the HAR can contain sensitive information, I've prepared a private upload link where you can securely send this to me. I will DM you the link shortly.

Dennis_Rietvink · January 28, 2020, 1:22pm

Hi Larry,

It seems the issue is indeed not OIDC related. I ran the test using the following kibana.yml

    server.name: kibana-customer
    server.host: "0.0.0.0"
    xpack.security.enabled: true
    logging.verbose: true
    xpack.security.authc.providers: [token]

logged into Kibana using a native user account
opened the Canvas dashboard in fullscreen with auto refresh set to every 5 seconds
got the same error after around 20 minutes
also noticed the same security related events in the kibana trace log:

{"type":"log","@timestamp":"2020-01-28T13:12:37Z","tags":["debug","plugins","security","token"],"pid":7,"message":"Trying to authenticate user request to /api/interpreter/fns."}
{"type":"log","@timestamp":"2020-01-28T13:12:37Z","tags":["debug","plugins","security","token"],"pid":7,"message":"Trying to authenticate via header."}
{"type":"log","@timestamp":"2020-01-28T13:12:37Z","tags":["debug","plugins","security","token"],"pid":7,"message":"Authorization header is not presented."}
{"type":"log","@timestamp":"2020-01-28T13:12:37Z","tags":["debug","plugins","security","token"],"pid":7,"message":"Trying to authenticate via state."}
{"type":"log","@timestamp":"2020-01-28T13:12:37Z","tags":["debug","plugins","security","token"],"pid":7,"message":"Failed to authenticate request via state: [security_exception] token expired, with { header={ WWW-Authenticate=\"Bearer realm=\\\"security\\\", error=\\\"invalid_token\\\", error_description=\\\"The access token expired\\\"\" } }"}
{"type":"log","@timestamp":"2020-01-28T13:12:37Z","tags":["debug","plugins","security","token"],"pid":7,"message":"Trying to refresh access token."}
{"type":"log","@timestamp":"2020-01-28T13:12:38Z","tags":["debug","plugins","security","tokens"],"pid":7,"message":"Failed to refresh access token: invalid_grant"}
{"type":"log","@timestamp":"2020-01-28T13:12:38Z","tags":["debug","plugins","security","tokens"],"pid":7,"message":"Refresh token is either expired or already used."}
{"type":"log","@timestamp":"2020-01-28T13:12:38Z","tags":["info","plugins","security","authentication"],"pid":7,"message":"Authentication attempt failed: Both access and refresh tokens are expired."}

I will upload the full tracelog and HAR using the link you send me.

Best,
Dennis

Larry_Gregory · January 28, 2020, 3:01pm

@Dennis_Rietvink, thanks for all of your help debugging this. I managed to figure out what's happening. There is a bug in Canvas specifically when using auth providers which leverage the token service.

I've opened an issue to track this, which explains the underlying problem in more detail: https://github.com/elastic/kibana/issues/56157

In the meantime, I do have a workaround available (sort of...). If you update your canvas workpad to include a Timelion expression as a datasource, then the workpad should continue to refresh, without causing a session timeout. You might not have a use-case for a Timelion expression though, so you might have to place one on there which is hidden by another element, just to force it in there...

If you don't need a Timelion data source, you can use this Timelion expression for some dummy-data: .static(value=0)

Dennis_Rietvink · January 28, 2020, 3:53pm

Thanks @Larry_Gregory for your swift responses and workaround.

Best,
Dennis

system · February 25, 2020, 3:54pm

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.

Topic		Replies	Views
Kibana session issues Kibana elastic-stack-security	9	1786	February 19, 2022
Avoiding session timeout Kibana elastic-stack-security	9	6681	November 21, 2019
Possible to disable session timeout for users in Elastic Cloud? Kibana elastic-stack-security	3	892	May 16, 2023
Kibana link is lost after authentication Kibana	12	1389	June 25, 2020
Kibana UI session timeout issue Kibana	4	605	November 13, 2020

Losing a session in a Canvas

Trial 1: Token auth provider

Trial 2: Capture a HAR

Related Topics