1

I have a Keycloak in a VPS running as SSO for the rest of the architecture. But every few days, without apparently any reason, in a single spike Keycloak uses all its available memory and enters in a blocked state.

Here's the server.log just before the last time it happened:

2016-06-21 21:24:29,963 DEBUG [org.keycloak.services] (default task-8) action: auth-username-password-form
2016-06-21 21:24:29,968 WARN  [org.keycloak.events] (default task-8) type=LOGIN_ERROR, realmId=186810ab-588b-48fd-a56c-f9c58bc370fa, clientId=registro, userId=null, ipAddress=101.62.141.157, error=user_not_found, auth_method=openid-connect, auth_type=code, redirect_uri=http://server.com/index.xhtml;jsessionid=yMRV-EkysuGJiXX0oVAU88uLcnZ2cGoV2xJR4-HY.ip-192-168-1-4, code_id=1e46ee1f-b620-45b6-8820-821a3248fa35, username=email@server.com
2016-06-21 21:24:29,971 DEBUG [org.keycloak.services] (default task-8) authenticator FAILURE_CHALLENGE: auth-username-password-form
2016-06-21 21:24:35,035 DEBUG [org.keycloak.services] (default task-7) authenticationAction
2016-06-21 21:24:35,035 DEBUG [org.keycloak.services] (default task-7) processAction: 5488581f-f2de-88ef-9dd4-4d8332176d48
2016-06-21 21:24:35,035 DEBUG [org.keycloak.services] (default task-7) check: auth-cookie requirement: ALTERNATIVE
2016-06-21 21:24:35,035 DEBUG [org.keycloak.services] (default task-7) execution is processed
2016-06-21 21:24:35,036 DEBUG [org.keycloak.services] (default task-7) check: auth-spnego requirement: DISABLED
2016-06-21 21:24:35,036 DEBUG [org.keycloak.services] (default task-7) execution is processed
2016-06-21 21:24:35,036 DEBUG [org.keycloak.services] (default task-7) check: null requirement: ALTERNATIVE
2016-06-21 21:24:35,036 DEBUG [org.keycloak.services] (default task-7) processAction: 5488581f-f2de-88ef-9dd4-4d8332976d48
2016-06-21 21:24:35,036 DEBUG [org.keycloak.services] (default task-7) check: auth-username-password-form requirement: REQUIRED
2016-06-21 21:24:35,036 DEBUG [org.keycloak.services] (default task-7) action: auth-username-password-form
2016-06-21 21:24:35,043 WARN  [org.keycloak.events] (default task-7) type=LOGIN_ERROR, realmId=186810ab-500b-48fd-a56c-f9c58bc370fa, clientId=registro, userId=null, ipAddress=101.62.141.157, error=user_not_found, auth_method=openid-connect, auth_type=code, redirect_uri=http://backoffice.trackingsport.com/index.xhtml;jsessionid=yMRV-EkysuGJiXX0oVAUrluLcnZ2cGoV2xJR4-HY.ip-192-168-1-4, code_id=1e46ee1f-b620-45b6-8820-821a3248fa35, username=email@server.com
2016-06-21 21:24:35,044 DEBUG [org.keycloak.services] (default task-7) authenticator FAILURE_CHALLENGE: auth-username-password-form
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) AUTHENTICATE
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) AUTHENTICATE ONLY
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) processFlow
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) check execution: auth-cookie requirement: ALTERNATIVE
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) authenticator: auth-cookie
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) invoke authenticator.authenticate
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) Could not find cookie: KEYCLOAK_IDENTITY
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) authenticator ATTEMPTED: auth-cookie
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) check execution: auth-spnego requirement: DISABLED
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) execution is processed
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) check execution: null requirement: ALTERNATIVE
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) execution is flow
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) processFlow
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) check execution: auth-username-password-form requirement: REQUIRED
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) authenticator: auth-username-password-form
2016-06-21 21:25:20,444 DEBUG [org.keycloak.services] (default task-13) invoke authenticator.authenticate
2016-06-21 21:25:20,445 DEBUG [org.keycloak.services] (default task-13) authenticator CHALLENGE: auth-username-password-form
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) AUTHENTICATE
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) AUTHENTICATE ONLY
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) processFlow
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) check execution: auth-cookie requirement: ALTERNATIVE
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) authenticator: auth-cookie
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) invoke authenticator.authenticate
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) Could not find cookie: KEYCLOAK_IDENTITY
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) authenticator ATTEMPTED: auth-cookie
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) check execution: auth-spnego requirement: DISABLED
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) execution is processed
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) check execution: null requirement: ALTERNATIVE
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) execution is flow
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) processFlow
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) check execution: auth-username-password-form requirement: REQUIRED
2016-06-21 21:25:27,492 DEBUG [org.keycloak.services] (default task-2) authenticator: auth-username-password-form

I'm completely lost here. The log level is at debug mode but I can't still see anything that gives me a clue about what's going on.

My question, how can I debug this? Have you experienced any situation similar to this one?

Victor Henriquez
  • 243
  • 1
  • 3
  • 8
  • 1
    What about looking in your other log files ... perhaps the oom killer came out to play. – user9517 Jun 29 '16 at 12:18
  • Which version of Keycloak are you using? There is a memory leak in Keycloak 1.9.8 which is discussed in: http://lists.jboss.org/pipermail/keycloak-user/2016-June/006658.html – Thomas Darimont Jun 29 '16 at 12:43
  • Keycloak 1.9.2, but we are thinking about upgrade to 1.9.8... but looking at your comment doesn't look like a good idea. – Victor Henriquez Jun 29 '16 at 13:12
  • By the way, so far I can't find anything important in other log files, not oom killer or any other thing so revealing, but I'll keep an eye on them next time this happens. – Victor Henriquez Jun 29 '16 at 13:15
  • 1
    FYI the memory leak discussion continues here: http://lists.jboss.org/pipermail/keycloak-user/2016-June/006771.html – Thomas Darimont Jun 29 '16 at 15:59

0 Answers0