Skip to content

Commit

Permalink
KEYCLOAK-531 Reduce info level logging
Browse files Browse the repository at this point in the history
  • Loading branch information
@stianst
stianst committed Aug 27, 2014
1 parent 269a0db commit 55bd889
Show file tree
Hide file tree
Showing 20 changed files with 67 additions and 143 deletions.
2 changes: 0 additions & 2 deletions core/src/test/java/org/keycloak/RSAVerifierTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -206,7 206,6 @@ public void testExpirationBad() throws Exception {
v = verifySkeletonKeyToken(encoded);
Assert.fail();
} catch (VerificationException ignored) {
System.out.println(ignored.getMessage());
}
}

Expand All @@ -225,7 224,6 @@ public void testTokenAuth() throws Exception {
try {
v = verifySkeletonKeyToken(encoded);
} catch (VerificationException ignored) {
System.out.println(ignored.getMessage());
}
}

Expand Down
4 changes: 0 additions & 4 deletions core/src/test/java/org/keycloak/SkeletonKeyTokenTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,8 24,6 @@ public void testToken() throws Exception {
token.addAccess("bar").addRole("user");

String json = JsonSerialization.writeValueAsString(token);
System.out.println(json);

token = JsonSerialization.readValue(json, AccessToken.class);
Assert.assertEquals("111", token.getId());
AccessToken.Access foo = token.getResourceAccess("foo");
Expand All @@ -47,8 45,6 @@ public void testRSA() throws Exception {
.jsonContent(token)
.rsa256(keyPair.getPrivate());

System.out.println(encoded);

JWSInput input = new JWSInput(encoded);

token = input.readJsonContent(AccessToken.class);
Expand Down
7 changes: 7 additions & 0 deletions docbook/reference/en/en-US/modules/MigrationFromOlderVersions.xml
View file
Original file line number Diff line number Diff line change
@@ -1,5 1,12 @@
<chapter id="Migration_from_older_versions">
<title>Migration from older versions</title>
<sect1>
<title>Migrating from 1.0 RC-1 to RC-2</title>
<itemizedlist>
<listitem>A lot of info level logging has been changed to debug. Also, a realm no longer has the jboss-logging audit listener by default.
If you want log output when users login, logout, change passwords, etc. enable the jboss-logging audit listener through the admin console.</listitem>
</itemizedlist>
</sect1>
<sect1>
<title>Migrating from 1.0 Beta 4 to RC-1</title>
<itemizedlist>
Expand Down
10 changes: 5 additions & 5 deletions ...ation/undertow/src/main/java/org/keycloak/adapters/undertow/KeycloakServletExtension.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 74,7 @@ private static InputStream getConfigInputStream(ServletContext context) {
if (is == null) {
String path = context.getInitParameter("keycloak.config.file");
if (path == null) {
log.info("**** using /WEB-INF/keycloak.json");
log.debug("using /WEB-INF/keycloak.json");
is = context.getResourceAsStream("/WEB-INF/keycloak.json");
} else {
try {
Expand All @@ -91,10 91,10 @@ private static InputStream getConfigInputStream(ServletContext context) {
@Override
public void handleDeployment(DeploymentInfo deploymentInfo, ServletContext servletContext) {
if (!isAuthenticationMechanismPresent(deploymentInfo, "KEYCLOAK")) {
log.info("auth-method is not keycloak!");
log.debug("auth-method is not keycloak!");
return;
}
log.info("KeycloakServletException initialization");
log.debug("KeycloakServletException initialization");
InputStream is = getConfigInputStream(servletContext);
KeycloakDeployment deployment = null;
if (is == null) {
Expand Down Expand Up @@ -139,14 139,14 @@ public Account verify(Credential credential) {
}
});

log.info("Setting jsession cookie path to: " deploymentInfo.getContextPath());
log.debug("Setting jsession cookie path to: " deploymentInfo.getContextPath());
ServletSessionConfig cookieConfig = new ServletSessionConfig();
cookieConfig.setPath(deploymentInfo.getContextPath());
deploymentInfo.setServletSessionConfig(cookieConfig);
}

protected ServletKeycloakAuthMech createAuthenticationMechanism(DeploymentInfo deploymentInfo, AdapterDeploymentContext deploymentContext, UndertowUserSessionManagement userSessionManagement) {
log.info("creating ServletKeycloakAuthMech");
log.debug("creating ServletKeycloakAuthMech");
return new ServletKeycloakAuthMech(deploymentContext, userSessionManagement, deploymentInfo.getConfidentialPortManager());
}
}
2 changes: 1 addition & 1 deletion model/api/src/main/java/org/keycloak/models/utils/RepresentationToModel.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -397,7 397,7 @@ public static ApplicationModel createApplication(RealmModel realm, ApplicationRe
if (resourceRep.getRedirectUris() != null) {
Set<String> origins = new HashSet<String>();
for (String redirectUri : resourceRep.getRedirectUris()) {
logger.info("add redirectUri to origin: " redirectUri);
logger.debugv("add redirect-uri to origin: {0}", redirectUri);
if (redirectUri.startsWith("http:")) {
URI uri = URI.create(redirectUri);
String origin = uri.getScheme() "://" uri.getHost();
Expand Down
6 changes: 3 additions & 3 deletions services/src/main/java/org/keycloak/services/DefaultKeycloakSessionFactory.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 38,7 @@ public void init() {

factories.put(factory.getId(), factory);

log.info("Loaded SPI " spi.getName() " (provider = " provider ")");
log.debugv("Loaded SPI {0} (provider = {1})", spi.getName(), provider);
} else {
for (ProviderFactory factory : ServiceLoader.load(spi.getProviderFactoryClass())) {
Config.Scope scope = Config.scope(spi.getName(), factory.getId());
Expand All @@ -51,9 51,9 @@ public void init() {
provider = factories.values().iterator().next().getId();
this.provider.put(spi.getProviderClass(), provider);

log.info("Loaded SPI " spi.getName() " (provider = " provider ")");
log.debugv("Loaded SPI {0} (provider = {1})", spi.getName(), provider);
} else {
log.info("Loaded SPI " spi.getName() " (providers = " factories.keySet() ")");
log.debugv("Loaded SPI {0} (providers = {1})", spi.getName(), factories.keySet());
}
}
}
Expand Down
2 changes: 0 additions & 2 deletions services/src/main/java/org/keycloak/services/managers/ApplianceBootstrap.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -60,8 60,6 @@ public void bootstrap(KeycloakSession session, String contextPath) {
realm.setRegistrationAllowed(false);
KeycloakModelUtils.generateRealmKeys(realm);

realm.setAuditListeners(Collections.singleton("jboss-logging"));

UserModel adminUser = session.users().addUser(realm, "admin");
adminUser.setEnabled(true);
UserCredentialModel password = new UserCredentialModel();
Expand Down
56 changes: 16 additions & 40 deletions services/src/main/java/org/keycloak/services/managers/AuthenticationManager.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -55,26 55,19 @@ public AuthenticationManager(BruteForceProtector protector) {

public static boolean isSessionValid(RealmModel realm, UserSessionModel userSession) {
if (userSession == null) {
logger.info("userSession was null");
logger.debug("No user session");
return false;
}
int currentTime = Time.currentTime();
int max = userSession.getStarted() realm.getSsoSessionMaxLifespan();
boolean valid = userSession != null && userSession.getLastSessionRefresh() realm.getSsoSessionIdleTimeout() > currentTime && max > currentTime;
if (!valid) {
logger.info("userSession.getLastSessionRefresh(): " userSession.getLastSessionRefresh());
logger.info("realm.getSsoSessionIdleTimeout(): " realm.getSsoSessionIdleTimeout());
logger.info("currentTime: " currentTime);
logger.info("max: " max);
}
return valid;
return userSession != null && userSession.getLastSessionRefresh() realm.getSsoSessionIdleTimeout() > currentTime && max > currentTime;
}

public static void logout(KeycloakSession session, RealmModel realm, UserSessionModel userSession, UriInfo uriInfo, ClientConnection connection) {
if (userSession == null) return;
UserModel user = userSession.getUser();

logger.infov("Logging out: {0} ({1})", user.getUsername(), userSession.getId());
logger.debugv("Logging out: {0} ({1})", user.getUsername(), userSession.getId());

session.sessions().removeUserSession(realm, userSession);
expireIdentityCookie(realm, uriInfo, connection);
Expand All @@ -86,7 79,6 @@ public static void logout(KeycloakSession session, RealmModel realm, UserSession


public AccessToken createIdentityToken(RealmModel realm, UserModel user, UserSessionModel session) {
logger.info("createIdentityToken");
AccessToken token = new AccessToken();
token.id(KeycloakModelUtils.generateId());
token.issuedNow();
Expand All @@ -102,17 94,15 @@ public AccessToken createIdentityToken(RealmModel realm, UserModel user, UserSes
}

public void createLoginCookie(RealmModel realm, UserModel user, UserSessionModel session, UriInfo uriInfo, ClientConnection connection) {
logger.info("createLoginCookie");
String cookiePath = getIdentityCookiePath(realm, uriInfo);
AccessToken identityToken = createIdentityToken(realm, user, session);
String encoded = encodeToken(realm, identityToken);
boolean secureOnly = realm.getSslRequired().isRequired(connection);
logger.debugv("creatingLoginCookie - name: {0} path: {1}", KEYCLOAK_IDENTITY_COOKIE, cookiePath);
int maxAge = NewCookie.DEFAULT_MAX_AGE;
if (session.isRememberMe()) {
maxAge = realm.getSsoSessionIdleTimeout();
logger.info("createLoginCookie maxAge: " maxAge);
}
logger.debugv("Create login cookie - name: {0}, path: {1}, max-age: {2}", KEYCLOAK_IDENTITY_COOKIE, cookiePath, maxAge);
CookieHelper.addCookie(KEYCLOAK_IDENTITY_COOKIE, encoded, cookiePath, null, null, maxAge, secureOnly, true);
//builder.cookie(new NewCookie(cookieName, encoded, cookiePath, null, null, maxAge, secureOnly));// todo httponly , true);

Expand Down Expand Up @@ -171,10 161,9 @@ public AuthResult authenticateIdentityCookie(KeycloakSession session, RealmModel
}

public AuthResult authenticateIdentityCookie(KeycloakSession session, RealmModel realm, UriInfo uriInfo, ClientConnection connection, HttpHeaders headers, boolean checkActive) {
logger.info("authenticateIdentityCookie");
Cookie cookie = headers.getCookies().get(KEYCLOAK_IDENTITY_COOKIE);
if (cookie == null || "".equals(cookie.getValue())) {
logger.infov("authenticateCookie could not find cookie: {0}", KEYCLOAK_IDENTITY_COOKIE);
logger.debugv("Could not find cookie: {0}", KEYCLOAK_IDENTITY_COOKIE);
return null;
}

Expand All @@ -191,43 180,39 @@ public AuthResult authenticateIdentityCookie(KeycloakSession session, RealmModel
protected AuthResult verifyIdentityToken(KeycloakSession session, RealmModel realm, UriInfo uriInfo, ClientConnection connection, boolean checkActive, String tokenString) {
try {
AccessToken token = RSATokenVerifier.verifyToken(tokenString, realm.getPublicKey(), realm.getName(), checkActive);
logger.info("identity token verified");
if (checkActive) {
logger.info("Checking if identity token is active");
if (!token.isActive() || token.getIssuedAt() < realm.getNotBefore()) {
logger.info("identity cookie expired");
logger.debug("identity cookie expired");
return null;
} else {
logger.info("token.isActive() : " token.isActive());
logger.info("token.issuedAt: " token.getIssuedAt());
logger.info("real.notbefore: " realm.getNotBefore());
logger.debugv("token not active - active: {0}, issued-at: {1}, not-before: {2}", token.isActive(), token.getIssuedAt(), realm.getNotBefore());
}
}

UserModel user = session.users().getUserById(token.getSubject(), realm);
if (user == null || !user.isEnabled() ) {
logger.info("Unknown user in identity token");
logger.debug("Unknown user in identity token");
return null;
}

UserSessionModel userSession = session.sessions().getUserSession(realm, token.getSessionState());
if (!isSessionValid(realm, userSession)) {
if (userSession != null) logout(session, realm, userSession, uriInfo, connection);
logger.info("User session not active");
logger.debug("User session not active");
return null;
}

return new AuthResult(user, userSession, token);
} catch (VerificationException e) {
logger.info("Failed to verify identity token", e);
logger.debug("Failed to verify identity token", e);
}
return null;
}

public AuthenticationStatus authenticateForm(KeycloakSession session, ClientConnection clientConnection, RealmModel realm, MultivaluedMap<String, String> formData) {
String username = formData.getFirst(FORM_USERNAME);
if (username == null) {
logger.warn("Username not provided");
logger.debug("Username not provided");
return AuthenticationStatus.INVALID_USER;
}

Expand Down Expand Up @@ -264,11 249,11 @@ protected AuthenticationStatus authenticateInternal(KeycloakSession session, Rea
UserModel user = KeycloakModelUtils.findUserByNameOrEmail(session, realm, username);

if (user == null) {
logger.warn("User " username " not found");
logger.debugv("User {0} not found", username);
return AuthenticationStatus.INVALID_USER;
}

if (!checkEnabled(user)) {
if (!user.isEnabled()) {
return AuthenticationStatus.ACCOUNT_DISABLED;
}

Expand All @@ -282,15 267,15 @@ protected AuthenticationStatus authenticateInternal(KeycloakSession session, Rea
List<UserCredentialModel> credentials = new LinkedList<UserCredentialModel>();
String password = formData.getFirst(CredentialRepresentation.PASSWORD);
if (password == null) {
logger.warn("Password not provided");
logger.debug("Password not provided");
return AuthenticationStatus.MISSING_PASSWORD;
}
credentials.add(UserCredentialModel.password(password));

if (user.isTotp()) {
String token = formData.getFirst(CredentialRepresentation.TOTP);
if (token == null) {
logger.warn("TOTP token not provided");
logger.debug("TOTP token not provided");
return AuthenticationStatus.MISSING_TOTP;
}
credentials.add(UserCredentialModel.totp(token));
Expand All @@ -311,7 296,7 @@ protected AuthenticationStatus authenticateInternal(KeycloakSession session, Rea
} else if (types.contains(CredentialRepresentation.SECRET)) {
String secret = formData.getFirst(CredentialRepresentation.SECRET);
if (secret == null) {
logger.warn("Secret not provided");
logger.debug("Secret not provided");
return AuthenticationStatus.MISSING_PASSWORD;
}
if (!session.users().validCredentials(realm, user, UserCredentialModel.secret(secret))) {
Expand All @@ -328,15 313,6 @@ protected AuthenticationStatus authenticateInternal(KeycloakSession session, Rea
}
}

private boolean checkEnabled(UserModel user) {
if (!user.isEnabled()) {
logger.warn("AccountProvider is disabled, contact admin. " user.getUsername());
return false;
} else {
return true;
}
}

public enum AuthenticationStatus {
SUCCESS, ACCOUNT_TEMPORARILY_DISABLED, ACCOUNT_DISABLED, ACTIONS_REQUIRED, INVALID_USER, INVALID_CREDENTIALS, MISSING_PASSWORD, MISSING_TOTP, FAILED
}
Expand Down
7 changes: 0 additions & 7 deletions services/src/main/java/org/keycloak/services/managers/RealmManager.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -86,8 86,6 @@ public RealmModel createRealm(String id, String name) {
setupAccountManagement(realm);
setupAdminConsole(realm);

realm.setAuditListeners(Collections.singleton("jboss-logging"));

return realm;
}

Expand Down Expand Up @@ -226,11 224,6 @@ public RealmModel importRealm(RealmRepresentation rep) {

RepresentationToModel.importRealm(session, rep, realm);


if (realm.getAuditListeners().size() == 0) {
realm.setAuditListeners(Collections.singleton("jboss-logging"));
}

// Refresh periodic sync tasks for configured federationProviders
List<UserFederationProviderModel> federationProviders = realm.getUserFederationProviders();
UsersSyncManager usersSyncManager = new UsersSyncManager();
Expand Down
Loading

0 comments on commit 55bd889

Please sign in to comment.