Trace Message on script's context.failure #16012

vozerov · 2022-12-15T08:24:42Z

vozerov
Dec 15, 2022

Hey there!

I have s small question about login failures in scripts. I got small script for users per client's authentication:

AuthenticationFlowError = Java.type("org.keycloak.authentication.AuthenticationFlowError");

function authenticate(context) {
var MANDATORY_ROLE = 'feature:authenticate';
var username = user ? user.username : "anonymous";

var client = session.getContext().getClient();

LOG.info("Checking access to authentication for client '" + client.getName() + "' through mandatory role '" + MANDATORY_ROLE + "' for user '" + username + "'");

var mandatoryRole = client.getRole(MANDATORY_ROLE);

if (mandatoryRole === null) {
LOG.debug("No mandatory role '" + MANDATORY_ROLE + "' for client '" + client.getName() + "'");
context.success();
return;
}

if (user.hasRole(mandatoryRole)) {
LOG.info("Successful authentication for user '" + username + "' with mandatory role '" + MANDATORY_ROLE + "' for client '" + client.getName() + "'");
context.success();
return;
}

LOG.info("Denied authentication for user '" + username + "' without mandatory role '" + MANDATORY_ROLE + "' for client '" + client.getName() + "'");
context.failure(AuthenticationFlowError.INVALID_USER);
}

It works fine, except one thing - when user failed to login i have a big stack trace in my log messages:

2022-12-15 08:15:06,586 INFO [org.keycloak.services] (executor-thread-0) KC-SERVICES0106: Created script engine 'Oracle Nashorn', version '11.0.17' for the mime type 'text/javascript'
2022-12-15 08:15:06,774 INFO [org.keycloak.authentication.authenticators.browser.ScriptBasedAuthenticator] (executor-thread-0) Checking access to authentication for client '${client_account-console}' through mandatory role 'feature:authenticate' for user 'vozerov'
2022-12-15 08:15:06,995 INFO [org.keycloak.authentication.authenticators.browser.ScriptBasedAuthenticator] (executor-thread-0) Denied authentication for user 'vozerov' without mandatory role 'feature:authenticate' for client '${client_account-console}'
2022-12-15 08:15:07,008 WARN [org.keycloak.services] (executor-thread-0) KC-SERVICES0013: Failed authentication: org.keycloak.authentication.AuthenticationFlowException
at org.keycloak.authentication.DefaultAuthenticationFlow.processResult(DefaultAuthenticationFlow.java:497)
at org.keycloak.authentication.DefaultAuthenticationFlow.processSingleFlowExecutionModel(DefaultAuthenticationFlow.java:448)
at org.keycloak.authentication.DefaultAuthenticationFlow.processFlow(DefaultAuthenticationFlow.java:250)
at org.keycloak.authentication.AuthenticationProcessor.authenticateOnly(AuthenticationProcessor.java:1017)
at org.keycloak.authentication.AuthenticationProcessor.authenticate(AuthenticationProcessor.java:879)
at org.keycloak.protocol.AuthorizationEndpointBase.handleBrowserAuthenticationRequest(AuthorizationEndpointBase.java:151)
at org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.buildAuthorizationCodeAuthorizationResponse(AuthorizationEndpoint.java:338)
at org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.process(AuthorizationEndpoint.java:194)
at org.keycloak.protocol.oidc.endpoints.AuthorizationEndpoint.buildGet(AuthorizationEndpoint.java:112)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)

I believe it's not a exeception - because script worked fine and just returned failure login. Why does stacktrace appear in log? I want to log warn messages, but without stacktrace info.

My versions:

Keycloak 20.0.2
JVM: 11.0.17 (Red Hat, Inc. OpenJDK 64-Bit Server VM 11.0.17+8-LTS)
OS: Linux 5.15.72-1.el7.3.x86_64 amd64

Thanks for your help!

Answered by bonnm

Dec 15, 2022

Hello,
Have you tried providing a form at failure and/or other AuthenticationFlowError Codes? I am using the code below and did not get a stack trace.

var form = context.form()
 .setAttribute("client", client)
 .setStatus(Status.FORBIDDEN)
 .createForm("error.ftl");
context.failure(AuthenticationFlowError.INVALID_CREDENTIALS, form);
return;

View full answer

bonnm · 2022-12-15T10:52:34Z

bonnm
Dec 15, 2022

Hello,
Have you tried providing a form at failure and/or other AuthenticationFlowError Codes? I am using the code below and did not get a stack trace.

var form = context.form()
 .setAttribute("client", client)
 .setStatus(Status.FORBIDDEN)
 .createForm("error.ftl");
context.failure(AuthenticationFlowError.INVALID_CREDENTIALS, form);
return;

1 reply

vozerov Dec 17, 2022
Author

@bonnm amazing! Thank you for idea about the forms. I've just refactored it a bit to produce valuable message for direct grant flow and for now it looks like:

  LOG.info("Denied authentication for user '" + username + "' without mandatory role '" + MANDATORY_ROLE + "' for client '" + client.getName() + "'");
  var challenge = null;

  if (context.getFlowPath() == null) {
    var errorRep = new OAuth2ErrorRepresentation(Errors.GENERIC_AUTHENTICATION_ERROR, Messages.ACCESS_DENIED);
    challenge = Response.status(Response.Status.FORBIDDEN.getStatusCode()).entity(errorRep).type(MediaType.APPLICATION_JSON_TYPE).build();
  } else {
    challenge = context.form().setError(Messages.ACCESS_DENIED).createErrorPage(Response.Status.FORBIDDEN);
  }

  context.failure(AuthenticationFlowError.INVALID_USER, challenge);

Also added some imports:

Response = Java.type("javax.ws.rs.core.Response");
Messages = Java.type("org.keycloak.services.messages.Messages");
Errors = Java.type("org.keycloak.events.Errors");
MediaType = Java.type("javax.ws.rs.core.MediaType");
OAuth2ErrorRepresentation = Java.type("org.keycloak.representations.idm.OAuth2ErrorRepresentation");

It's not my code really, i tried to use this example:

keycloak/services/src/main/java/org/keycloak/authentication/authenticators/sessionlimits/UserSessionLimitsAuthenticator.java

Line 149 in a14501d

if(context.getFlowPath() == null) {

.

Once more - thanks for your help!

Navigation Menu

Repository navigation

Trace Message on script's context.failure #16012

Uh oh!

{{title}}

Uh oh!

Uh oh!

{{editor}}'s edit

{{editor}}'s edit

Uh oh!

Replies: 1 comment 1 reply

Uh oh!

{{title}}

Uh oh!

Uh oh!

{{editor}}'s edit

{{editor}}'s edit

Uh oh!

Uh oh!

{{title}}

Uh oh!

Uh oh!

{{editor}}'s edit

{{editor}}'s edit

Uh oh!

Select a reply

Uh oh!

Trace Message on script's context.failure #16012

Uh oh!

Uh oh!

vozerov Dec 15, 2022

Replies: 1 comment · 1 reply

Uh oh!

Uh oh!

bonnm Dec 15, 2022

Uh oh!

Uh oh!

vozerov Dec 17, 2022 Author

vozerov
Dec 15, 2022

Replies: 1 comment 1 reply

bonnm
Dec 15, 2022

vozerov Dec 17, 2022
Author