diff --git a/authentication/source/java/ch/systemsx/cisd/authentication/DefaultSessionManager.java b/authentication/source/java/ch/systemsx/cisd/authentication/DefaultSessionManager.java index d8913fa6042a648554247b8bde94a266bf515a12..09bd32e4632d35b7b6a60370bd487b2730310641 100644 --- a/authentication/source/java/ch/systemsx/cisd/authentication/DefaultSessionManager.java +++ b/authentication/source/java/ch/systemsx/cisd/authentication/DefaultSessionManager.java @@ -56,7 +56,7 @@ public class DefaultSessionManager<T extends BasicSession> implements ISessionMa { private static final String LOGOUT_PREFIX = "LOGOUT: "; - private static final String LOGIN_PREFIX = "LOGIN: "; + private static final String LOGIN_PREFIX_TEMPLATE = "(%dms) LOGIN: "; private static final char SESSION_TOKEN_SEPARATOR = '-'; @@ -336,11 +336,12 @@ public class DefaultSessionManager<T extends BasicSession> implements ISessionMa return session != null && session.hasExpired(); } - private void logAuthenticed(final T session) + private void logAuthenticed(final T session, final long timeToLoginMillis) { if (operationLog.isInfoEnabled()) { - operationLog.info(LOGIN_PREFIX + (session.isAnonymous() ? "Anonymous user" : "User") + operationLog.info(String.format(LOGIN_PREFIX_TEMPLATE, timeToLoginMillis) + + (session.isAnonymous() ? "Anonymous user" : "User") + " '" + session.getUserName() + "' has been successfully authenticated from host '" + getRemoteHost() + "'. Session token: '" + session.getSessionToken() + "'."); @@ -349,17 +350,20 @@ public class DefaultSessionManager<T extends BasicSession> implements ISessionMa authenticationLog.info(prefix + ": login"); } - private void logFailedAuthentication(final String user) + private void logFailedAuthentication(final String user, final long timeToLoginMillis) { - operationLog.warn(LOGIN_PREFIX + "User '" + user + "' failed to authenticate from host '" + operationLog.warn(String.format(LOGIN_PREFIX_TEMPLATE, timeToLoginMillis) + "User '" + user + + "' failed to authenticate from host '" + getRemoteHost() + "'."); logAuthenticationFailure(user); } - private void logSessionFailure(final String user, final RuntimeException ex) + private void logSessionFailure(final String user, final RuntimeException ex, + final long timeToLoginMillis) { logAuthenticationFailure(user); - operationLog.error(LOGIN_PREFIX + "Error when trying to authenticate user '" + user + "'.", + operationLog.error(String.format(LOGIN_PREFIX_TEMPLATE, timeToLoginMillis) + + "Error when trying to authenticate user '" + user + "'.", ex); } @@ -516,11 +520,12 @@ public class DefaultSessionManager<T extends BasicSession> implements ISessionMa public String tryToOpenSession(String userID, IPrincipalProvider principalProvider) { checkIfNotBlank(userID, "user"); + final long now = System.currentTimeMillis(); try { String sessionToken = null; - final long now = System.currentTimeMillis(); final Principal principalOrNull = principalProvider.tryToGetPrincipal(userID); + final long timeToLogin = System.currentTimeMillis() - now; final boolean isAuthenticated = Principal.isAuthenticated(principalOrNull); if (isAuthenticated) { @@ -529,7 +534,7 @@ public class DefaultSessionManager<T extends BasicSession> implements ISessionMa final T session = createAndStoreSession(principalOrNull.getUserId(), principalOrNull, now); sessionToken = session.getSessionToken(); - logAuthenticed(session); + logAuthenticed(session, timeToLogin); } catch (final IllegalArgumentException ex) { // getPrincipal() of an authenticated user should not fail, if it does, this @@ -538,12 +543,12 @@ public class DefaultSessionManager<T extends BasicSession> implements ISessionMa } } else { - logFailedAuthentication(userID); + logFailedAuthentication(userID, timeToLogin); } return sessionToken; } catch (final RuntimeException ex) { - logSessionFailure(userID, ex); + logSessionFailure(userID, ex, System.currentTimeMillis() - now); throw ex; } diff --git a/authentication/sourceTest/java/ch/systemsx/cisd/authentication/DefaultSessionManagerTest.java b/authentication/sourceTest/java/ch/systemsx/cisd/authentication/DefaultSessionManagerTest.java index 60b6d39bf18f47976ceb778af8d2bf00929ff6ad..0af4f0b4a35493670524c4b184ed33c1d490fb3b 100644 --- a/authentication/sourceTest/java/ch/systemsx/cisd/authentication/DefaultSessionManagerTest.java +++ b/authentication/sourceTest/java/ch/systemsx/cisd/authentication/DefaultSessionManagerTest.java @@ -151,7 +151,7 @@ public class DefaultSessionManagerTest "INFO OPERATION.DefaultSessionManager - Create dummy session monitor" + OSUtilities.LINE_SEPARATOR + "INFO OPERATION.DefaultSessionManager - " - + "LOGIN: User 'bla' has been successfully authenticated from host 'remote-host'. Session token: '" + + "(0ms) LOGIN: User 'bla' has been successfully authenticated from host 'remote-host'. Session token: '" + token + "'." + OSUtilities.LINE_SEPARATOR @@ -187,7 +187,7 @@ public class DefaultSessionManagerTest "INFO OPERATION.DefaultSessionManager - Create dummy session monitor" + OSUtilities.LINE_SEPARATOR + "INFO OPERATION.DefaultSessionManager - " - + "LOGIN: User 'bla' has been successfully authenticated from host 'remote-host'. Session token: '" + + "(0ms) LOGIN: User 'bla' has been successfully authenticated from host 'remote-host'. Session token: '" + token + "'." + OSUtilities.LINE_SEPARATOR @@ -217,7 +217,7 @@ public class DefaultSessionManagerTest assert null == sessionManager.tryToOpenSession(user, "blub"); assertEquals( "WARN OPERATION.DefaultSessionManager - " - + "LOGIN: User 'bla' failed to authenticate from host 'remote-host'." + + "(0ms) LOGIN: User 'bla' failed to authenticate from host 'remote-host'." + OSUtilities.LINE_SEPARATOR + "INFO AUTH.DefaultSessionManager - [USER:'bla', HOST:'remote-host']: login ...FAILED", logRecorder.getLogContent()); @@ -345,7 +345,7 @@ public class DefaultSessionManagerTest "INFO OPERATION.DefaultSessionManager - Create dummy session monitor" + OSUtilities.LINE_SEPARATOR + "INFO OPERATION.DefaultSessionManager - " - + "LOGIN: User 'u1' has been successfully authenticated from host 'remote-host'. Session token: '" + + "(0ms) LOGIN: User 'u1' has been successfully authenticated from host 'remote-host'. Session token: '" + token + "'." + OSUtilities.LINE_SEPARATOR