Merge pull request #686 from mposolda/master

KEYCLOAK-674 Reduce info level logging in adapters
This commit is contained in:
Marek Posolda 2014-09-10 16:04:48 +02:00
commit 5e51204114
13 changed files with 71 additions and 48 deletions

View file

@ -1,7 +1,6 @@
package org.keycloak.adapters; package org.keycloak.adapters;
import org.apache.http.client.HttpClient; import org.apache.http.client.HttpClient;
import org.jboss.logging.Logger;
import org.keycloak.ServiceUrlConstants; import org.keycloak.ServiceUrlConstants;
import org.keycloak.enums.SslRequired; import org.keycloak.enums.SslRequired;
import org.keycloak.util.KeycloakUriBuilder; import org.keycloak.util.KeycloakUriBuilder;
@ -16,7 +15,6 @@ import java.util.Map;
* @version $Revision: 1 $ * @version $Revision: 1 $
*/ */
public class KeycloakDeployment { public class KeycloakDeployment {
private static final Logger log = Logger.getLogger(KeycloakDeployment.class);
protected boolean relativeUrls; protected boolean relativeUrls;
protected String realm; protected String realm;

View file

@ -109,7 +109,7 @@ public abstract class OAuthRequestAuthenticator {
protected String getRedirectUri(String state) { protected String getRedirectUri(String state) {
String url = getRequestUrl(); String url = getRequestUrl();
log.infof("callback uri: %s", url); log.debugf("callback uri: %s", url);
if (!facade.getRequest().isSecure() && deployment.getSslRequired().isRequired(facade.getRequest().getRemoteAddr())) { if (!facade.getRequest().isSecure() && deployment.getSslRequired().isRequired(facade.getRequest().getRemoteAddr())) {
int port = sslRedirectPort(); int port = sslRedirectPort();
if (port < 0) { if (port < 0) {
@ -148,7 +148,7 @@ public abstract class OAuthRequestAuthenticator {
exchange.getResponse().setStatus(403); exchange.getResponse().setStatus(403);
return true; return true;
} }
log.info("Sending redirect to login page: " + redirect); log.debug("Sending redirect to login page: " + redirect);
exchange.getResponse().setStatus(302); exchange.getResponse().setStatus(302);
exchange.getResponse().setCookie(deployment.getStateCookieName(), state, /* need to set path? */ null, null, -1, deployment.getSslRequired().isRequired(facade.getRequest().getRemoteAddr()), false); exchange.getResponse().setCookie(deployment.getStateCookieName(), state, /* need to set path? */ null, null, -1, deployment.getSslRequired().isRequired(facade.getRequest().getRemoteAddr()), false);
exchange.getResponse().setHeader("Location", redirect); exchange.getResponse().setHeader("Location", redirect);
@ -165,7 +165,7 @@ public abstract class OAuthRequestAuthenticator {
return challenge(400); return challenge(400);
} }
// reset the cookie // reset the cookie
log.info("** reseting application state cookie"); log.debug("** reseting application state cookie");
facade.getResponse().resetCookie(deployment.getStateCookieName(), stateCookie.getPath()); facade.getResponse().resetCookie(deployment.getStateCookieName(), stateCookie.getPath());
String stateCookieValue = getCookieValue(deployment.getStateCookieName()); String stateCookieValue = getCookieValue(deployment.getStateCookieName());
@ -187,7 +187,7 @@ public abstract class OAuthRequestAuthenticator {
public AuthOutcome authenticate() { public AuthOutcome authenticate() {
String code = getCode(); String code = getCode();
if (code == null) { if (code == null) {
log.info("there was no code"); log.debug("there was no code");
String error = getError(); String error = getError();
if (error != null) { if (error != null) {
// todo how do we send a response? // todo how do we send a response?
@ -195,13 +195,13 @@ public abstract class OAuthRequestAuthenticator {
challenge = challenge(400); challenge = challenge(400);
return AuthOutcome.FAILED; return AuthOutcome.FAILED;
} else { } else {
log.info("redirecting to auth server"); log.debug("redirecting to auth server");
challenge = loginRedirect(); challenge = loginRedirect();
saveRequest(); saveRequest();
return AuthOutcome.NOT_ATTEMPTED; return AuthOutcome.NOT_ATTEMPTED;
} }
} else { } else {
log.info("there was a code, resolving"); log.debug("there was a code, resolving");
challenge = resolveCode(code); challenge = resolveCode(code);
if (challenge != null) { if (challenge != null) {
return AuthOutcome.FAILED; return AuthOutcome.FAILED;
@ -246,7 +246,7 @@ public abstract class OAuthRequestAuthenticator {
return challenge(403); return challenge(403);
} }
log.info("checking state cookie for after code"); log.debug("checking state cookie for after code");
AuthChallenge challenge = checkStateCookie(); AuthChallenge challenge = checkStateCookie();
if (challenge != null) return challenge; if (challenge != null) return challenge;
@ -292,7 +292,7 @@ public abstract class OAuthRequestAuthenticator {
log.error("Stale token"); log.error("Stale token");
return challenge(403); return challenge(403);
} }
log.info("successful authenticated"); log.debug("successful authenticated");
return null; return null;
} }

View file

@ -113,7 +113,9 @@ public class PreAuthActionsHandler {
} }
protected void handleLogout() { protected void handleLogout() {
log.info("K_LOGOUT sent"); if (log.isTraceEnabled()) {
log.trace("K_LOGOUT sent");
}
try { try {
JWSInput token = verifyAdminRequest(); JWSInput token = verifyAdminRequest();
if (token == null) { if (token == null) {
@ -123,12 +125,12 @@ public class PreAuthActionsHandler {
if (!validateAction(action)) return; if (!validateAction(action)) return;
String user = action.getUser(); String user = action.getUser();
if (user != null) { if (user != null) {
log.info("logout of session for: " + user); log.debug("logout of session for: " + user);
userSessionManagement.logoutUser(user); userSessionManagement.logoutUser(user);
} else if (action.getSession() != null) { } else if (action.getSession() != null) {
userSessionManagement.logoutKeycloakSession(action.getSession()); userSessionManagement.logoutKeycloakSession(action.getSession());
} else { } else {
log.info("logout of all sessions"); log.debug("logout of all sessions");
if (action.getNotBefore() > deployment.getNotBefore()) { if (action.getNotBefore() > deployment.getNotBefore()) {
deployment.setNotBefore(action.getNotBefore()); deployment.setNotBefore(action.getNotBefore());
} }
@ -142,7 +144,9 @@ public class PreAuthActionsHandler {
protected void handlePushNotBefore() { protected void handlePushNotBefore() {
log.info("K_PUSH_NOT_BEFORE sent"); if (log.isTraceEnabled()) {
log.trace("K_PUSH_NOT_BEFORE sent");
}
try { try {
JWSInput token = verifyAdminRequest(); JWSInput token = verifyAdminRequest();
if (token == null) { if (token == null) {
@ -205,7 +209,9 @@ public class PreAuthActionsHandler {
} }
protected void handleGetSessionStats() { protected void handleGetSessionStats() {
log.info("K_GET_SESSION_STATS sent"); if (log.isTraceEnabled()) {
log.trace("K_GET_SESSION_STATS sent");
}
try { try {
JWSInput token = verifyAdminRequest(); JWSInput token = verifyAdminRequest();
if (token == null) return; if (token == null) return;
@ -229,7 +235,9 @@ public class PreAuthActionsHandler {
} }
} }
protected void handleGetUserStats() { protected void handleGetUserStats() {
log.info("K_GET_USER_STATS sent"); if (log.isTraceEnabled()) {
log.trace("K_GET_USER_STATS sent");
}
try { try {
JWSInput token = verifyAdminRequest(); JWSInput token = verifyAdminRequest();
if (token == null) return; if (token == null) return;

View file

@ -63,11 +63,15 @@ public class RefreshableKeycloakSecurityContext extends KeycloakSecurityContext
} }
public void refreshExpiredToken() { public void refreshExpiredToken() {
log.info("checking whether to refresh."); if (log.isTraceEnabled()) {
log.trace("checking whether to refresh.");
}
if (isActive()) return; if (isActive()) return;
if (this.deployment == null || refreshToken == null) return; // Might be serialized in HttpSession? if (this.deployment == null || refreshToken == null) return; // Might be serialized in HttpSession?
log.info("Doing refresh"); if (log.isTraceEnabled()) {
log.trace("Doing refresh");
}
AccessTokenResponse response = null; AccessTokenResponse response = null;
try { try {
response = ServerRequest.invokeRefresh(deployment, refreshToken); response = ServerRequest.invokeRefresh(deployment, refreshToken);
@ -78,12 +82,14 @@ public class RefreshableKeycloakSecurityContext extends KeycloakSecurityContext
log.error("Refresh token failure status: " + httpFailure.getStatus() + " " + httpFailure.getError()); log.error("Refresh token failure status: " + httpFailure.getStatus() + " " + httpFailure.getError());
return; return;
} }
log.info("received refresh response"); if (log.isTraceEnabled()) {
log.trace("received refresh response");
}
String tokenString = response.getToken(); String tokenString = response.getToken();
AccessToken token = null; AccessToken token = null;
try { try {
token = RSATokenVerifier.verifyToken(tokenString, deployment.getRealmKey(), deployment.getRealm()); token = RSATokenVerifier.verifyToken(tokenString, deployment.getRealmKey(), deployment.getRealm());
log.info("Token Verification succeeded!"); log.debug("Token Verification succeeded!");
} catch (VerificationException e) { } catch (VerificationException e) {
log.error("failed verification of token"); log.error("failed verification of token");
} }

View file

@ -31,29 +31,36 @@ public abstract class RequestAuthenticator {
} }
public AuthOutcome authenticate() { public AuthOutcome authenticate() {
log.info("--> authenticate()"); if (log.isTraceEnabled()) {
log.trace("--> authenticate()");
}
BearerTokenRequestAuthenticator bearer = createBearerTokenAuthenticator(); BearerTokenRequestAuthenticator bearer = createBearerTokenAuthenticator();
log.info("try bearer"); if (log.isTraceEnabled()) {
log.trace("try bearer");
}
AuthOutcome outcome = bearer.authenticate(facade); AuthOutcome outcome = bearer.authenticate(facade);
if (outcome == AuthOutcome.FAILED) { if (outcome == AuthOutcome.FAILED) {
challenge = bearer.getChallenge(); challenge = bearer.getChallenge();
log.info("Bearer FAILED"); log.debug("Bearer FAILED");
return AuthOutcome.FAILED; return AuthOutcome.FAILED;
} else if (outcome == AuthOutcome.AUTHENTICATED) { } else if (outcome == AuthOutcome.AUTHENTICATED) {
if (verifySSL()) return AuthOutcome.FAILED; if (verifySSL()) return AuthOutcome.FAILED;
completeAuthentication(bearer); completeAuthentication(bearer);
log.info("Bearer AUTHENTICATED"); log.debug("Bearer AUTHENTICATED");
return AuthOutcome.AUTHENTICATED; return AuthOutcome.AUTHENTICATED;
} else if (deployment.isBearerOnly()) { } else if (deployment.isBearerOnly()) {
challenge = bearer.getChallenge(); challenge = bearer.getChallenge();
log.info("NOT_ATTEMPTED: bearer only"); log.debug("NOT_ATTEMPTED: bearer only");
return AuthOutcome.NOT_ATTEMPTED; return AuthOutcome.NOT_ATTEMPTED;
} }
log.info("try oauth"); if (log.isTraceEnabled()) {
log.trace("try oauth");
}
if (isCached()) { if (isCached()) {
if (verifySSL()) return AuthOutcome.FAILED; if (verifySSL()) return AuthOutcome.FAILED;
log.info("AUTHENTICATED: was cached"); log.debug("AUTHENTICATED: was cached");
return AuthOutcome.AUTHENTICATED; return AuthOutcome.AUTHENTICATED;
} }
@ -77,7 +84,7 @@ public abstract class RequestAuthenticator {
facade.getResponse().setStatus(302); facade.getResponse().setStatus(302);
facade.getResponse().end(); facade.getResponse().end();
log.info("AUTHENTICATED"); log.debug("AUTHENTICATED");
return AuthOutcome.AUTHENTICATED; return AuthOutcome.AUTHENTICATED;
} }

View file

@ -31,7 +31,7 @@ public class AuthenticatedActionsValve extends ValveBase {
public AuthenticatedActionsValve(AdapterDeploymentContext deploymentContext, Valve next, Container container, ObjectName controller) { public AuthenticatedActionsValve(AdapterDeploymentContext deploymentContext, Valve next, Container container, ObjectName controller) {
this.deploymentContext = deploymentContext; this.deploymentContext = deploymentContext;
if (next == null) throw new RuntimeException("WTF is next null?!"); if (next == null) throw new RuntimeException("Next valve is null!!!");
setNext(next); setNext(next);
setContainer(container); setContainer(container);
setController(controller); setController(controller);

View file

@ -123,7 +123,9 @@ public class KeycloakAuthenticatorValve extends FormAuthenticator implements Lif
@Override @Override
public void invoke(Request request, Response response) throws IOException, ServletException { public void invoke(Request request, Response response) throws IOException, ServletException {
try { try {
log.info("invoke"); if (log.isTraceEnabled()) {
log.trace("invoke");
}
CatalinaHttpFacade facade = new CatalinaHttpFacade(request, response); CatalinaHttpFacade facade = new CatalinaHttpFacade(request, response);
PreAuthActionsHandler handler = new PreAuthActionsHandler(userSessionManagement, deploymentContext, facade); PreAuthActionsHandler handler = new PreAuthActionsHandler(userSessionManagement, deploymentContext, facade);
if (handler.handleRequest()) { if (handler.handleRequest()) {
@ -137,7 +139,9 @@ public class KeycloakAuthenticatorValve extends FormAuthenticator implements Lif
@Override @Override
public boolean authenticate(Request request, HttpServletResponse response, LoginConfig config) throws IOException { public boolean authenticate(Request request, HttpServletResponse response, LoginConfig config) throws IOException {
log.info("*** authenticate"); if (log.isTraceEnabled()) {
log.trace("*** authenticate");
}
CatalinaHttpFacade facade = new CatalinaHttpFacade(request, response); CatalinaHttpFacade facade = new CatalinaHttpFacade(request, response);
KeycloakDeployment deployment = deploymentContext.resolveDeployment(facade); KeycloakDeployment deployment = deploymentContext.resolveDeployment(facade);
if (deployment == null || !deployment.isConfigured()) { if (deployment == null || !deployment.isConfigured()) {

View file

@ -29,7 +29,7 @@ public class KeycloakLoginModule extends AbstractServerLoginModule {
@SuppressWarnings("unchecked") @SuppressWarnings("unchecked")
@Override @Override
public boolean login() throws LoginException { public boolean login() throws LoginException {
log.info("KeycloakLoginModule.login()"); log.debug("KeycloakLoginModule.login()");
if (super.login() == true) { if (super.login() == true) {
log.info("super.login()==true"); log.info("super.login()==true");
return true; return true;
@ -37,7 +37,7 @@ public class KeycloakLoginModule extends AbstractServerLoginModule {
Object credential = getCredential(); Object credential = getCredential();
if (credential != null && (credential instanceof KeycloakAccount)) { if (credential != null && (credential instanceof KeycloakAccount)) {
log.info("Found Account"); log.debug("Found Account");
KeycloakAccount account = (KeycloakAccount)credential; KeycloakAccount account = (KeycloakAccount)credential;
roleSet = account.getRoles(); roleSet = account.getRoles();
identity = account.getPrincipal(); identity = account.getPrincipal();

View file

@ -48,11 +48,15 @@ public class KeycloakUndertowAccount implements Account, Serializable, KeycloakA
protected void setRoles(AccessToken accessToken) { protected void setRoles(AccessToken accessToken) {
Set<String> roles = null; Set<String> roles = null;
if (session.getDeployment().isUseResourceRoleMappings()) { if (session.getDeployment().isUseResourceRoleMappings()) {
log.info("useResourceRoleMappings"); if (log.isTraceEnabled()) {
log.trace("useResourceRoleMappings");
}
AccessToken.Access access = accessToken.getResourceAccess(session.getDeployment().getResourceName()); AccessToken.Access access = accessToken.getResourceAccess(session.getDeployment().getResourceName());
if (access != null) roles = access.getRoles(); if (access != null) roles = access.getRoles();
} else { } else {
log.info("use realm role mappings"); if (log.isTraceEnabled()) {
log.trace("use realm role mappings");
}
AccessToken.Access access = accessToken.getRealmAccess(); AccessToken.Access access = accessToken.getRealmAccess();
if (access != null) roles = access.getRoles(); if (access != null) roles = access.getRoles();
} }
@ -88,18 +92,18 @@ public class KeycloakUndertowAccount implements Account, Serializable, KeycloakA
public boolean isActive() { public boolean isActive() {
// this object may have been serialized, so we need to reset realm config/metadata // this object may have been serialized, so we need to reset realm config/metadata
if (session.isActive()) { if (session.isActive()) {
log.info("session is active"); log.debug("session is active");
return true; return true;
} }
log.info("session is not active try refresh"); log.debug("session is not active try refresh");
session.refreshExpiredToken(); session.refreshExpiredToken();
if (!session.isActive()) { if (!session.isActive()) {
log.info("session is not active return with failure"); log.debug("session is not active return with failure");
return false; return false;
} }
log.info("refresh succeeded"); log.debug("refresh succeeded");
setRoles(session.getToken()); setRoles(session.getToken());
return true; return true;

View file

@ -49,22 +49,22 @@ public class ServletRequestAuthenticator extends UndertowRequestAuthenticator {
HttpServletRequest req = (HttpServletRequest) servletRequestContext.getServletRequest(); HttpServletRequest req = (HttpServletRequest) servletRequestContext.getServletRequest();
HttpSession session = req.getSession(false); HttpSession session = req.getSession(false);
if (session == null) { if (session == null) {
log.info("session was null, returning null"); log.debug("session was null, returning null");
return false; return false;
} }
KeycloakUndertowAccount account = (KeycloakUndertowAccount)session.getAttribute(KeycloakUndertowAccount.class.getName()); KeycloakUndertowAccount account = (KeycloakUndertowAccount)session.getAttribute(KeycloakUndertowAccount.class.getName());
if (account == null) { if (account == null) {
log.info("Account was not in session, returning null"); log.debug("Account was not in session, returning null");
return false; return false;
} }
account.setDeployment(deployment); account.setDeployment(deployment);
if (account.isActive()) { if (account.isActive()) {
log.info("Cached account found"); log.debug("Cached account found");
securityContext.authenticationComplete(account, "KEYCLOAK", false); securityContext.authenticationComplete(account, "KEYCLOAK", false);
propagateKeycloakContext( account); propagateKeycloakContext( account);
return true; return true;
} }
log.info("Account was not active, returning null"); log.debug("Account was not active, returning null");
session.setAttribute(KeycloakUndertowAccount.class.getName(), null); session.setAttribute(KeycloakUndertowAccount.class.getName(), null);
return false; return false;
} }

View file

@ -21,7 +21,6 @@ import io.undertow.server.handlers.CookieImpl;
import io.undertow.util.AttachmentKey; import io.undertow.util.AttachmentKey;
import io.undertow.util.Headers; import io.undertow.util.Headers;
import io.undertow.util.HttpString; import io.undertow.util.HttpString;
import org.jboss.logging.Logger;
import org.keycloak.KeycloakSecurityContext; import org.keycloak.KeycloakSecurityContext;
import org.keycloak.adapters.HttpFacade; import org.keycloak.adapters.HttpFacade;
import org.keycloak.util.KeycloakUriBuilder; import org.keycloak.util.KeycloakUriBuilder;
@ -39,7 +38,6 @@ import java.util.Map;
* @version $Revision: 1 $ * @version $Revision: 1 $
*/ */
public class UndertowHttpFacade implements HttpFacade { public class UndertowHttpFacade implements HttpFacade {
private static final Logger log = Logger.getLogger(UndertowHttpFacade.class);
public static final AttachmentKey<KeycloakSecurityContext> KEYCLOAK_SECURITY_CONTEXT_KEY = AttachmentKey.create(KeycloakSecurityContext.class); public static final AttachmentKey<KeycloakSecurityContext> KEYCLOAK_SECURITY_CONTEXT_KEY = AttachmentKey.create(KeycloakSecurityContext.class);
protected HttpServerExchange exchange; protected HttpServerExchange exchange;

View file

@ -24,7 +24,6 @@ import io.undertow.server.HttpServerExchange;
import io.undertow.server.session.Session; import io.undertow.server.session.Session;
import io.undertow.util.AttachmentKey; import io.undertow.util.AttachmentKey;
import io.undertow.util.Sessions; import io.undertow.util.Sessions;
import org.jboss.logging.Logger;
import org.keycloak.adapters.AdapterDeploymentContext; import org.keycloak.adapters.AdapterDeploymentContext;
import org.keycloak.adapters.AuthChallenge; import org.keycloak.adapters.AuthChallenge;
import org.keycloak.adapters.AuthOutcome; import org.keycloak.adapters.AuthOutcome;
@ -36,7 +35,6 @@ import org.keycloak.adapters.RequestAuthenticator;
* @author Stan Silvert ssilvert@redhat.com (C) 2014 Red Hat Inc. * @author Stan Silvert ssilvert@redhat.com (C) 2014 Red Hat Inc.
*/ */
public abstract class UndertowKeycloakAuthMech implements AuthenticationMechanism { public abstract class UndertowKeycloakAuthMech implements AuthenticationMechanism {
private static final Logger log = Logger.getLogger(UndertowKeycloakAuthMech.class);
public static final AttachmentKey<AuthChallenge> KEYCLOAK_CHALLENGE_ATTACHMENT_KEY = AttachmentKey.create(AuthChallenge.class); public static final AttachmentKey<AuthChallenge> KEYCLOAK_CHALLENGE_ATTACHMENT_KEY = AttachmentKey.create(AuthChallenge.class);
protected AdapterDeploymentContext deploymentContext; protected AdapterDeploymentContext deploymentContext;

View file

@ -39,7 +39,7 @@ public class WildflyRequestAuthenticator extends ServletRequestAuthenticator {
protected void propagateKeycloakContext(KeycloakUndertowAccount account) { protected void propagateKeycloakContext(KeycloakUndertowAccount account) {
super.propagateKeycloakContext(account); super.propagateKeycloakContext(account);
SecurityInfoHelper.propagateSessionInfo(account); SecurityInfoHelper.propagateSessionInfo(account);
log.info("propagate security context to wildfly"); log.debug("propagate security context to wildfly");
Subject subject = new Subject(); Subject subject = new Subject();
Set<Principal> principals = subject.getPrincipals(); Set<Principal> principals = subject.getPrincipals();
principals.add(account.getPrincipal()); principals.add(account.getPrincipal());