Merged V4.1-BUG-FIX to HEAD

42804: Merged BRANCHES/DEV/BELARUS/V4.1-BUG-FIX-2012_10_17 to BRANCHES/DEV/V4.1-BUG-FIX:
      42748: ALF-14200: Adding Invalid Aspects Via CMIS ATOM API Results in NullPointerException
   42810: Fix for ALF-15276 - sys:locale Attribute No Longer Available From jsnode
   42814: ALF-15276 - small improvement to remove duplicated data from response
   42824: ALF-15048: Merged PATCHES/V4.0.2 to V4.1-BUG-FIX
        42724: ALF-16048: CLONE - Version history doesn't go beyond two versions (0.1 and 0.2) when dragged and dropped via CIFS from Mac Lion OSx
        42739: ALF-16048: New files missing from previous check in
        42742: ALF-16048: Another missing file.
   42839: ALF-16417: Fix "Hybrid Sync - can retain invalid cloud tickets in a local cache"
      - retry once for invalid auth 
      - also externalise the implicit/default cache config
   42849: NodeDAO: Added new method to retrieve specific store ID
    - public Pair<Long, StoreRef> getStore(StoreRef storeRef);
   42857: Merged DEV to V4.1-BUG-FIX
      42821: ALF-13506 : WCMQS Example Application Caching Causes Changes to Inconsistently Appear on the Editorial Web Site
             Concurrency was improved for AssetImpl class.
             The returned values of the collections were made unmodifiable in the classes which implement Resource interface.
   42872: ALF-15601: "Performance issue using CMIS method getChildren() - gets version history"
   - avoids getting the version history (an expensive operation) if possible i.e. in the case of current version (live) nodes like for getChildren
   42900: Merged DEV to V4.1-BUG-FIX
      42734: ALF-15335 : 'external' authentication subsystem debug information too scarce
         Extended debug information in the authentication subsystem.


git-svn-id: https://svn.alfresco.com/repos/alfresco-enterprise/alfresco/HEAD/root@42904 c4b6b30b-aa2e-2d43-bbcb-ca4b014f7261

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
                }
             }
          }
-         
+         if (logger.isDebugEnabled())
-         // session invalidated - return to login screen
+             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<User>()
@@ -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<cookies.length; i++)
          {
             if (COOKIE_ALFUSER.equals(cookies[i].getName()))
             {
                // found cookie
+               if (logger.isDebugEnabled())
+                   logger.debug("Found Alfresco auth cookie: " + cookies[i].toString());
                authCookie = cookies[i];
                break;
             }
@@ -616,13 +718,18 @@ public final class AuthenticationHelper
    public static String getAuthCookieValue(Cookie authCookie)
    {
       String authCookieValue = authCookie.getValue();
+      if (logger.isDebugEnabled())
+          logger.debug("Decoding auth cookie: " + authCookieValue);
       if (authCookieValue == null)
       {
          return null;
       }
       try
       {
-         return new String(Base64.decode(authCookieValue), "UTF-8");
+         String decodedAuthCoockieValue = new String(Base64.decode(authCookieValue), "UTF-8");
+         if (logger.isDebugEnabled())
+             logger.debug("The auth cookie is: " + decodedAuthCoockieValue);
+         return decodedAuthCoockieValue;
       }
       catch (UnsupportedEncodingException e)
       {

source/java/org/alfresco/web/app/servlet/DefaultRemoteUserMapper.java

@@ -29,6 +29,8 @@ import org.alfresco.repo.security.authentication.AuthenticationUtil.RunAsWork;
 import org.alfresco.service.cmr.security.PersonService;
 
 import org.alfresco.repo.webdav.auth.RemoteUserMapper;
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
 /**
  * A default {@link RemoteUserMapper} implementation. Extracts a user ID using
  * {@link HttpServletRequest#getRemoteUser()} and optionally from a configured request header. If there is no configured
@@ -57,6 +59,8 @@ public class DefaultRemoteUserMapper implements RemoteUserMapper, ActivateableBe
     /** The person service. */
     private PersonService personService;
 
+    static Log logger = LogFactory.getLog(DefaultRemoteUserMapper.class);
+
     /**
      * Sets the name of the remote user used to 'proxy' requests securely in the name of another user. Typically this
      * remote identity will be protected by an SSL client certificate.
@@ -123,25 +127,43 @@ public class DefaultRemoteUserMapper implements RemoteUserMapper, ActivateableBe
      */
     public String getRemoteUser(HttpServletRequest request)
     {
+        if (logger.isDebugEnabled())
+            logger.debug("Getting RemoteUser from http request.");
         if (!this.isEnabled)
         {
+            if (logger.isDebugEnabled())
+                logger.debug("DefaultRemoteUserMapper is disabled, returning null.");
             return null;
         }
         String remoteUserId = request.getRemoteUser();
         String headerUserId = extractUserFromProxyHeader(request);
+        if (logger.isDebugEnabled())
+        {
+            logger.debug("The remote user id is: " + remoteUserId);
+            logger.debug("The header user id is: " + headerUserId);
+            logger.debug("The proxy user name is: " + this.proxyUserName);
+        }
         if (this.proxyUserName == null)
         {
             // Normalize the user ID taking into account case sensitivity settings
-            return normalizeUserId(headerUserId != null ? headerUserId : remoteUserId);
+            String normalizedUserId =  normalizeUserId(headerUserId != null ? headerUserId : remoteUserId);
+            if (logger.isDebugEnabled())
+                logger.debug("Returning " + normalizedUserId);
+            return normalizedUserId;
         }
         else if (remoteUserId == null)
         {
+            if (logger.isDebugEnabled())
+                logger.debug("Returning null");
             return null;
         }
         else
         {
             // Normalize the user ID taking into account case sensitivity settings
-            return normalizeUserId(remoteUserId.equals(this.proxyUserName) ? headerUserId : remoteUserId);
+            String normalizedUserId =  normalizeUserId(remoteUserId.equals(this.proxyUserName) ? headerUserId : remoteUserId);
+            if (logger.isDebugEnabled())
+                logger.debug("Returning " + normalizedUserId);
+            return normalizedUserId;
         }
     }
 
@@ -165,6 +187,8 @@ public class DefaultRemoteUserMapper implements RemoteUserMapper, ActivateableBe
                 return personService.getUserIdentifier(userId);
             }
         }, AuthenticationUtil.getSystemUserName());
+        if (logger.isDebugEnabled())
+            logger.debug("The normalized user name is: " + normalized + " for user id " + userId);
         return normalized == null ? userId : normalized;
     }