Incorrect refresh token lifetime

Summary

I’m experiencing incorrect refresh token lifetimes. The logging shows too short lifetimes. But there is no way to log the raw OIDC response to verify it.

Login:
2021-05-14T05:04:02.451Z	info	gatekeeper/handlers.go:218	issuing access token for user	{"email": "...", "expires": "2021-05-14T05:34:02Z", "duration": "29m59.548584938s"}
2021-05-14T05:04:02.451Z	debug	gatekeeper/misc.go:147	parsed refresh token with new duration	{"new duration": 43135.548101591}

Refresh:
2021-05-14T05:34:09.621Z	info	gatekeeper/middleware.go:251	accces token for user has expired, attemping to refresh the token	{"client_ip": "192.168.206.95:44356", "email": "..."}
2021-05-14T05:34:10.194Z	info	gatekeeper/middleware.go:304	injecting the refreshed access token cookie	{"client_ip": "192.168.206.95:44356", "cookie_name": "kc-access", "email": "...", "refresh_expires_in": 1798.999883207, "expires_in": 1798.805463817}
2021-05-14T05:34:10.194Z	debug	gatekeeper/middleware.go:324	renew refresh cookie with new refresh token	{"refresh_expires_in": 1798.999883207}

But when calling the refresh with curl I can’t see these short lifetime values:

### login
{
  "access_token": {
    "exp": 1620977883,
    "iat": 1620976083,
    "jti": "00cfb2fd-bad2-4224-9a68-6703477710de",
    "iss": "https://...",
    "aud": "<CLIENT_ID>",
    "sub": "8e5a64d6-efc2-4133-a863-6948fcf94bca",
    "typ": "Bearer",
    "azp": "<CLIENT_ID>",
    "session_state": "412d459f-5a81-4173-a18f-b31a489fda5c",
    "acr": "1",
    "scope": "email profile",
    "clientId": "<CLIENT_ID>",
    "email_verified": false,
    "clientHost": "...",
    "preferred_username": "service-account-<CLIENT_ID>",
    "clientAddress": "..."
  },
  "expires_in": 1800,
  "refresh_expires_in": 43200,
  "refresh_token": {
    "exp": 1621019283,
    "iat": 1620976083,
    "jti": "9522d0ca-60a3-4b58-8ddc-04c92d563962",
    "iss": "https://...",
    "aud": "https://...",
    "sub": "8e5a64d6-efc2-4133-a863-6948fcf94bca",
    "typ": "Refresh",
    "azp": "<CLIENT_ID>",
    "session_state": "412d459f-5a81-4173-a18f-b31a489fda5c",
    "scope": "email profile"
  },
  "token_type": "bearer",
  "not-before-policy": 0,
  "session_state": "412d459f-5a81-4173-a18f-b31a489fda5c",
  "scope": "email profile"
}

### refresh token
{
  "access_token": {
    "exp": 1620980622,
    "iat": 1620978822,
    "jti": "01e6e709-f79f-4818-acef-c5003d777794",
    "iss": "https://...",
    "aud": "<CLIENT_ID>",
    "sub": "8e5a64d6-efc2-4133-a863-6948fcf94bca",
    "typ": "Bearer",
    "azp": "<CLIENT_ID>",
    "session_state": "412d459f-5a81-4173-a18f-b31a489fda5c",
    "acr": "1",
    "scope": "email profile",
    "clientId": "<CLIENT_ID>",
    "email_verified": false,
    "clientHost": "...",
    "preferred_username": "service-account-<CLIENT_ID>",
    "clientAddress": "..."
  },
  "expires_in": 1800,
  "refresh_expires_in": 40461,
  "refresh_token": {
    "exp": 1621019283,
    "iat": 1620978822,
    "jti": "2ab4bbdb-7e41-4c3d-97f4-ebcf03970823",
    "iss": "https://...",
    "aud": "https://...",
    "sub": "8e5a64d6-efc2-4133-a863-6948fcf94bca",
    "typ": "Refresh",
    "azp": "<CLIENT_ID>",
    "session_state": "412d459f-5a81-4173-a18f-b31a489fda5c",
    "scope": "email profile"
  },
  "token_type": "bearer",
  "not-before-policy": 0,
  "session_state": "412d459f-5a81-4173-a18f-b31a489fda5c",
  "scope": "email profile"
}

Environment

Version of everything that it’s running in your environment:

• OS: Linux
• Kernel (e.g. uname -a): Linux 9915836b-10fa-476b-6352-9b34 5.4.0-72-generic #80~18.04.1-Ubuntu SMP Mon Apr 12 23:26:25 UTC 2021 x86_64 Linux
• Go (e.g. go version)
• Server (e.g. Keycloak or any other IdP): Keycloak
• Gatekeeper: 1.3.1 (the official from here)

Expected Results

Fix the wrong lifetime handling and allow to log the raw OIDC request / response.

Actual Results

Every now an then it’s happening the Keycloak server is responding “Token is not active” on the refresh, but this is happening long time before the configured lifetime of 12h on the Keycloak server. The described situation above doesn’t make very confident the problem is completely server sited.

Steps to reproduce

Don’t know.

Additional Information