diff --git a/source/java/org/alfresco/web/app/servlet/AuthenticationHelper.java b/source/java/org/alfresco/web/app/servlet/AuthenticationHelper.java index 56c6ed02db..88974bea61 100644 --- a/source/java/org/alfresco/web/app/servlet/AuthenticationHelper.java +++ b/source/java/org/alfresco/web/app/servlet/AuthenticationHelper.java @@ -1,5 +1,5 @@ /* - * Copyright (C) 2005-2010 Alfresco Software Limited. + * Copyright (C) 2005-2012 Alfresco Software Limited. * * This file is part of Alfresco * @@ -105,15 +105,21 @@ public final class AuthenticationHelper */ public static void setupThread(ServletContext sc, HttpServletRequest req, HttpServletResponse res, boolean useInterfaceLanguage) { + if (logger.isDebugEnabled()) + logger.debug("Setting up the request thread."); // setup faces context FacesContext fc = Application.inPortalServer() ? AlfrescoFacesPortlet.getFacesContext(req) : FacesHelper .getFacesContext(req, res, sc); // Set the current locale and language (overriding the one already decoded from the Accept-Language header I18NUtil.setLocale(Application.getLanguage(req.getSession(), Application.getClientConfig(fc).isLanguageSelect() && useInterfaceLanguage)); - + if (logger.isDebugEnabled()) + logger.debug("The general locale is : " + I18NUtil.getLocale()); + // Programatically retrieve the UserPreferencesBean from JSF UserPreferencesBean userPreferencesBean = (UserPreferencesBean) FacesHelper.getManagedBean(fc, "UserPreferencesBean"); + if (logger.isDebugEnabled()) + logger.debug("The UserPreferencesBean is : " + userPreferencesBean); if (userPreferencesBean != null) { String contentFilterLanguageStr = userPreferencesBean.getContentFilterLanguage(); @@ -127,6 +133,8 @@ public final class AuthenticationHelper // Nothing has been selected, so remove the content filter I18NUtil.setContentLocale(null); } + if (logger.isDebugEnabled()) + logger.debug("The content locale is : " + I18NUtil.getContentLocale()); } } @@ -162,6 +170,8 @@ public final class AuthenticationHelper ServletContext sc, HttpServletRequest req, HttpServletResponse res, boolean forceGuest, boolean allowGuest) throws IOException { + if (logger.isDebugEnabled()) + logger.debug("Authenticating the current user using session based Ticket information."); // retrieve the User object User user = getUser(sc, req, res); @@ -171,6 +181,8 @@ public final class AuthenticationHelper LoginBean loginBean = null; if (Application.inPortalServer() == false) { + if (logger.isDebugEnabled()) + logger.debug("We're not in the portal, getting the login bean."); loginBean = (LoginBean)session.getAttribute(LOGIN_BEAN); } @@ -178,18 +190,25 @@ public final class AuthenticationHelper WebApplicationContext wc = WebApplicationContextUtils.getRequiredWebApplicationContext(sc); AuthenticationService auth = (AuthenticationService)wc.getBean(AUTHENTICATION_SERVICE); + if (logger.isDebugEnabled()) + logger.debug("Force guest is: " + forceGuest); if (user == null || forceGuest) { + if (logger.isDebugEnabled()) + logger.debug("The user is null."); // Check for the session invalidated flag - this is set by the Logout action in the LoginBean // it signals a forced Logout and means we should not immediately attempt a relogin as Guest. // The attribute is removed from the session by the login.jsp page after the Cookie containing // the last stored username string is cleared. if (session.getAttribute(AuthenticationHelper.SESSION_INVALIDATED) == null) { + if (logger.isDebugEnabled()) + logger.debug("The session is not invalidated."); Cookie authCookie = getAuthCookie(req); if (allowGuest == true && (authCookie == null || forceGuest)) { - // no previous authentication or forced Guest - attempt Guest access + if (logger.isDebugEnabled()) + logger.debug("No previous authentication or forced Guest - attempt Guest access."); try { auth.authenticateAsGuest(); @@ -203,12 +222,15 @@ public final class AuthenticationHelper // remove the session invalidated flag session.removeAttribute(AuthenticationHelper.SESSION_INVALIDATED); + if (logger.isDebugEnabled()) + logger.debug("Successfully authenticated as guest."); // it is the responsibilty of the caller to handle the Guest return status return AuthenticationStatus.Guest; } catch (AuthenticationException guestError) { - // Expected if Guest access not allowed - continue to login page as usual + if (logger.isDebugEnabled()) + logger.debug("An AuthenticationException occurred, expected if Guest access not allowed - continue to login page as usual", guestError); } catch (AccessDeniedException accessError) { @@ -216,7 +238,7 @@ public final class AuthenticationHelper AuthenticationService unprotAuthService = (AuthenticationService)wc.getBean(UNPROTECTED_AUTH_SERVICE); unprotAuthService.invalidateTicket(unprotAuthService.getCurrentTicket()); unprotAuthService.clearCurrentSecurityContext(); - logger.warn("Unable to login as Guest: " + accessError.getMessage()); + logger.warn("Unable to login as Guest: ", accessError); } catch (Throwable e) { @@ -228,16 +250,20 @@ public final class AuthenticationHelper } } } - - // session invalidated - return to login screen + if (logger.isDebugEnabled()) + logger.debug("Session invalidated - return to login screen."); return AuthenticationStatus.Failure; } else - { + { + if (logger.isDebugEnabled()) + logger.debug("The user is: " + user.getUserName()); // set last authentication username cookie value String loginName; if (loginBean != null && (loginName = loginBean.getUsernameInternal()) != null) { + if (logger.isDebugEnabled()) + logger.debug("Set last authentication username cookie value"); setUsernameCookie(req, res, loginName); } @@ -257,6 +283,8 @@ public final class AuthenticationHelper ServletContext context, HttpServletRequest httpRequest, HttpServletResponse httpResponse, String ticket) throws IOException { + if (logger.isDebugEnabled()) + logger.debug("Authenticate the current user using the supplied Ticket value."); // setup the authentication context WebApplicationContext wc = WebApplicationContextUtils.getRequiredWebApplicationContext(context); AuthenticationService auth = (AuthenticationService)wc.getBean(AUTHENTICATION_SERVICE); @@ -267,9 +295,13 @@ public final class AuthenticationHelper SessionUser user = (SessionUser)session.getAttribute(AuthenticationHelper.AUTHENTICATION_USER); if (user != null && !user.getTicket().equals(ticket)) { + if (logger.isDebugEnabled()) + logger.debug("Found a previously-cached user with the wrong identity."); session.removeAttribute(AUTHENTICATION_USER); if (!Application.inPortalServer()) { + if (logger.isDebugEnabled()) + logger.debug("The server is not running in a portal, invalidating session."); session.invalidate(); session = httpRequest.getSession(); } @@ -279,23 +311,32 @@ public final class AuthenticationHelper // Validate the ticket and associate it with the session auth.validate(ticket); - // Cache a new user in the session if required if (user == null) { + if (logger.isDebugEnabled()) + logger.debug("Ticket is valid; caching a new user in the session."); setUser(context, httpRequest, auth.getCurrentUserName(), ticket, false); } + else if (logger.isDebugEnabled()) + logger.debug("Ticket is valid; retaining cached user in session."); } catch (AuthenticationException authErr) { + if (logger.isDebugEnabled()) + logger.debug("An AuthenticationException occured: ", authErr); session.removeAttribute(AUTHENTICATION_USER); if (!Application.inPortalServer()) { + if (logger.isDebugEnabled()) + logger.debug("The server is not running in a portal, invalidating session."); session.invalidate(); } return AuthenticationStatus.Failure; } catch (Throwable e) { + if (logger.isDebugEnabled()) + logger.debug("Authentication failed due to unexpected error", e); // Some other kind of serious failure AuthenticationService unprotAuthService = (AuthenticationService)wc.getBean(UNPROTECTED_AUTH_SERVICE); unprotAuthService.invalidateTicket(unprotAuthService.getCurrentTicket()); @@ -327,6 +368,8 @@ public final class AuthenticationHelper public static User setUser(ServletContext context, HttpServletRequest req, String currentUsername, String ticket, boolean externalAuth) { + if (logger.isDebugEnabled()) + logger.debug("Creating an object for " + currentUsername + " and storing it in the session"); WebApplicationContext wc = WebApplicationContextUtils.getRequiredWebApplicationContext(context); User user = createUser(wc, currentUsername, ticket); @@ -347,6 +390,8 @@ public final class AuthenticationHelper */ private static void setExternalAuth(HttpSession session, boolean externalAuth) { + if (logger.isDebugEnabled()) + logger.debug("Settings the external authentication flag on the session to " + externalAuth); if (externalAuth) { session.setAttribute(LoginBean.LOGIN_EXTERNAL_AUTH, Boolean.TRUE); @@ -370,6 +415,8 @@ public final class AuthenticationHelper */ private static User createUser(final WebApplicationContext wc, final String currentUsername, final String ticket) { + if (logger.isDebugEnabled()) + logger.debug("Creating an object for " + currentUsername + " with ticket: " + ticket); final ServiceRegistry services = (ServiceRegistry) wc.getBean(ServiceRegistry.SERVICE_REGISTRY); return services.getTransactionService().getRetryingTransactionHelper().doInTransaction( new RetryingTransactionHelper.RetryingTransactionCallback() @@ -404,6 +451,8 @@ public final class AuthenticationHelper */ public static User portalGuestAuthenticate(WebApplicationContext ctx, AuthenticationService auth) { + if (logger.isDebugEnabled()) + logger.debug("Authenticating the current user as Guest in a portal."); try { auth.authenticateAsGuest(); @@ -412,7 +461,8 @@ public final class AuthenticationHelper } catch (AuthenticationException guestError) { - // Expected if Guest access not allowed - continue to login page as usual + if (logger.isDebugEnabled()) + logger.debug("An AuthenticationException occurred, expected if Guest access not allowed - continue to login page as usual", guestError); } catch (AccessDeniedException accessError) { @@ -424,6 +474,8 @@ public final class AuthenticationHelper } catch (Throwable e) { + if (logger.isDebugEnabled()) + logger.debug("Unexpected error authenticating as Guest in a portal.", e); // Some other kind of serious failure to report AuthenticationService unprotAuthService = (AuthenticationService) ctx.getBean(UNPROTECTED_AUTH_SERVICE); unprotAuthService.invalidateTicket(unprotAuthService.getCurrentTicket()); @@ -451,8 +503,26 @@ public final class AuthenticationHelper RemoteUserMapper remoteUserMapper = (RemoteUserMapper) wc.getBean(REMOTE_USER_MAPPER); if (!(remoteUserMapper instanceof ActivateableBean) || ((ActivateableBean) remoteUserMapper).isActive()) { + if (logger.isDebugEnabled()) + logger.debug("Remote user mapper configured and active. Asking for external user ID."); userId = remoteUserMapper.getRemoteUser(httpRequest); } + else if (logger.isDebugEnabled()) + { + logger.debug("No active remote user mapper."); + } + if (logger.isDebugEnabled()) + { + if (userId == null) + { + logger.debug("No external user ID in request."); + } + else + { + logger.debug("Extracted external user ID from request: " + userId); + } + } + return userId; } @@ -483,6 +553,8 @@ public final class AuthenticationHelper // been known to leak in but shouldn't now) if (sessionUser != null) { + if (logger.isDebugEnabled()) + logger.debug("SessionUser is: " + sessionUser.getUserName()); AuthenticationService auth = (AuthenticationService) wc.getBean(AUTHENTICATION_SERVICE); try { @@ -499,9 +571,13 @@ public final class AuthenticationHelper } catch (AuthenticationException authErr) { + if (logger.isDebugEnabled()) + logger.debug("An authentication error occured while setting the session user", authErr); session.removeAttribute(AUTHENTICATION_USER); if (!Application.inPortalServer()) { + if (logger.isDebugEnabled()) + logger.debug("Invalidating the session."); session.invalidate(); } } @@ -513,9 +589,13 @@ public final class AuthenticationHelper // We have a previously-cached user with the wrong identity - replace them if (user != null && !user.getUserName().equals(userId)) { + if (logger.isDebugEnabled()) + logger.debug("We have a previously-cached user with the wrong identity - replace them"); session.removeAttribute(AUTHENTICATION_USER); if (!Application.inPortalServer()) { + if (logger.isDebugEnabled()) + logger.debug("Invalidating session."); session.invalidate(); } user = null; @@ -523,21 +603,29 @@ public final class AuthenticationHelper if (user == null) { + if (logger.isDebugEnabled()) + logger.debug("There are no previously-cached users."); // If we have been authenticated by other means, just propagate through the user identity AuthenticationComponent authenticationComponent = (AuthenticationComponent) wc .getBean(AUTHENTICATION_COMPONENT); try { + if (logger.isDebugEnabled()) + logger.debug("We have been authenticated by other means, authenticating the user: " + userId); authenticationComponent.setCurrentUser(userId); AuthenticationService authenticationService = (AuthenticationService) wc.getBean(AUTHENTICATION_SERVICE); user = setUser(sc, httpRequest, userId, authenticationService.getCurrentTicket(), true); } catch (AuthenticationException authErr) { + if (logger.isDebugEnabled()) + logger.debug("An authentication error occured while setting the session user" , authErr); // Allow for an invalid external user ID to be indicated session.removeAttribute(AUTHENTICATION_USER); if (!Application.inPortalServer()) { + if (logger.isDebugEnabled()) + logger.debug("Invalidating the session."); session.invalidate(); } } @@ -555,12 +643,16 @@ public final class AuthenticationHelper */ public static void setUsernameCookie(HttpServletRequest httpRequest, HttpServletResponse httpResponse, String username) { + if (logger.isDebugEnabled()) + logger.debug("Setting up the Alfresco auth cookie for " + username); Cookie authCookie = getAuthCookie(httpRequest); // Let's Base 64 encode the username so it is a legal cookie value String encodedUsername; try { encodedUsername = Base64.encodeBytes(username.getBytes("UTF-8")); + if (logger.isDebugEnabled()) + logger.debug("Base 64 encode the username: " + encodedUsername); } catch (UnsupportedEncodingException e) { @@ -568,10 +660,14 @@ public final class AuthenticationHelper } if (authCookie == null) { + if (logger.isDebugEnabled()) + logger.debug("No Alfresco auth cookie wa found, creating new one."); authCookie = new Cookie(COOKIE_ALFUSER, encodedUsername); } else { + if (logger.isDebugEnabled()) + logger.debug("Updating the previous Alfresco auth cookie value."); authCookie.setValue(encodedUsername); } authCookie.setPath(httpRequest.getContextPath()); @@ -589,15 +685,21 @@ public final class AuthenticationHelper */ public static Cookie getAuthCookie(HttpServletRequest httpRequest) { + if (logger.isDebugEnabled()) + logger.debug("Searching for Alfresco auth cookie."); Cookie authCookie = null; Cookie[] cookies = httpRequest.getCookies(); if (cookies != null) { + if (logger.isDebugEnabled()) + logger.debug("Cookies present."); for (int i=0; i