diff --git a/src/main/java/org/alfresco/repo/security/authentication/AlfrescoSecureContextImpl.java b/src/main/java/org/alfresco/repo/security/authentication/AlfrescoSecureContextImpl.java index 5f16e38ae2..17d7f277dd 100644 --- a/src/main/java/org/alfresco/repo/security/authentication/AlfrescoSecureContextImpl.java +++ b/src/main/java/org/alfresco/repo/security/authentication/AlfrescoSecureContextImpl.java @@ -27,6 +27,8 @@ package org.alfresco.repo.security.authentication; import net.sf.acegisecurity.Authentication; import net.sf.acegisecurity.context.ContextInvalidException; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; /** * Hold an Alfresco extended security context @@ -36,6 +38,8 @@ import net.sf.acegisecurity.context.ContextInvalidException; */ public class AlfrescoSecureContextImpl implements AlfrescoSecureContext { + Log logger = LogFactory.getLog(getClass()); + private static final long serialVersionUID = -8893133731693272549L; private Authentication realAuthentication; @@ -81,11 +85,19 @@ public class AlfrescoSecureContextImpl implements AlfrescoSecureContext public void setEffectiveAuthentication(Authentication effictiveAuthentication) { + if (logger.isTraceEnabled()) + { + logger.trace("Setting effective authentication to: " + AuthenticationUtil.getMaskedUsername(effictiveAuthentication)); + } this.effectiveAuthentication = effictiveAuthentication; } public void setRealAuthentication(Authentication realAuthentication) { + if (logger.isTraceEnabled()) + { + logger.trace("Setting real authentication to: " + AuthenticationUtil.getMaskedUsername(realAuthentication)); + } this.realAuthentication = realAuthentication; } @@ -133,21 +145,21 @@ public class AlfrescoSecureContextImpl implements AlfrescoSecureContext if (realAuthentication == null) { - builder.append("Real authenticaion = null"); + builder.append("Real authentication = null"); } else { - builder.append("Real authenticaion = " + realAuthentication.toString()); + builder.append("Real authentication = " + AuthenticationUtil.getMaskedUsername(realAuthentication)); } builder.append(", "); if (effectiveAuthentication == null) { - builder.append("Effective authenticaion = null"); + builder.append("Effective authentication = null"); } else { - builder.append("Effective authenticaion = " + effectiveAuthentication.toString()); + builder.append("Effective authentication = " +AuthenticationUtil.getMaskedUsername(effectiveAuthentication)); } builder.append(", "); diff --git a/src/main/java/org/alfresco/repo/security/authentication/AuthenticationUtil.java b/src/main/java/org/alfresco/repo/security/authentication/AuthenticationUtil.java index 6c288247f0..93972805b9 100644 --- a/src/main/java/org/alfresco/repo/security/authentication/AuthenticationUtil.java +++ b/src/main/java/org/alfresco/repo/security/authentication/AuthenticationUtil.java @@ -54,7 +54,7 @@ import org.springframework.beans.factory.InitializingBean; @AlfrescoPublicApi public class AuthenticationUtil implements InitializingBean { - static Log s_logger = LogFactory.getLog(AuthenticationUtil.class); + static Log logger = LogFactory.getLog(AuthenticationUtil.class); @AlfrescoPublicApi public interface RunAsWork { @@ -94,8 +94,10 @@ public class AuthenticationUtil implements InitializingBean public static void setMtEnabled(boolean mtEnabled) { - if (s_logger.isDebugEnabled()) - s_logger.debug("MT is enabled: " + mtEnabled); + if (logger.isDebugEnabled()) + { + logger.debug("MT is enabled: " + mtEnabled); + } AuthenticationUtil.mtEnabled = mtEnabled; } @@ -104,6 +106,39 @@ public class AuthenticationUtil implements InitializingBean return AuthenticationUtil.mtEnabled; } + public static String maskUsername(String userName) + { + if (userName != null) + { + try + { + if (userName.length() >= 2) + { + return userName.substring(0, 2) + new String(new char[(userName.length() - 2)]).replace("\0", "*"); + } + } + catch (Exception e) + { + if (logger.isDebugEnabled()) + { + logger.debug("Failed to mask the username because: " + e.getMessage(), e); + } + } + return userName; + } + return null; + } + + public static String getMaskedUsername(Authentication authentication) + { + String extractedUsername = null; + if (authentication != null && authentication.getPrincipal() != null) + { + extractedUsername = getUserName(authentication); + } + return maskUsername(extractedUsername); + } + public AuthenticationUtil() { super(); @@ -231,16 +266,20 @@ public class AuthenticationUtil implements InitializingBean } else { - if (s_logger.isDebugEnabled()) - s_logger.debug("Setting fully authenticated principal: " + authentication.getName()); + if (logger.isTraceEnabled()) + { + logger.trace("Setting fully authenticated principal: " + getMaskedUsername(authentication)); + } Context context = ContextHolder.getContext(); AlfrescoSecureContext sc = null; if ((context == null) || !(context instanceof AlfrescoSecureContext)) { - if (s_logger.isDebugEnabled()) - s_logger.debug("Creating new secure context."); sc = new AlfrescoSecureContextImpl(); ContextHolder.setContext(sc); + if (logger.isTraceEnabled()) + { + logger.trace("Setting new secure context: " + sc + " on thread: " + Thread.currentThread().getName()); + } } else { @@ -307,16 +346,20 @@ public class AuthenticationUtil implements InitializingBean } else { - if (s_logger.isDebugEnabled()) - s_logger.debug("Setting RunAs principal: " + authentication.getName()); + if (logger.isTraceEnabled()) + { + logger.trace("Setting RunAs principal: " + getMaskedUsername(authentication)); + } Context context = ContextHolder.getContext(); AlfrescoSecureContext sc = null; if ((context == null) || !(context instanceof AlfrescoSecureContext)) { - if (s_logger.isDebugEnabled()) - s_logger.debug("Creating new secure context."); sc = new AlfrescoSecureContextImpl(); ContextHolder.setContext(sc); + if (logger.isTraceEnabled()) + { + logger.trace("Setting new secure context: " + sc + " on thread: " + Thread.currentThread().getName()); + } } else { @@ -325,8 +368,10 @@ public class AuthenticationUtil implements InitializingBean authentication.setAuthenticated(true); if (sc.getRealAuthentication() == null) { - if (s_logger.isDebugEnabled()) - s_logger.debug("There is no fully authenticated prinipal. Setting fully authenticated principal: " + authentication.getName()); + if (logger.isTraceEnabled()) + { + logger.trace("There is no fully authenticated principal. Setting fully authenticated principal: " + getMaskedUsername(authentication)); + } sc.setRealAuthentication(authentication); } sc.setEffectiveAuthentication(authentication); @@ -500,8 +545,10 @@ public class AuthenticationUtil implements InitializingBean */ public static void clearCurrentSecurityContext() { - if (s_logger.isDebugEnabled()) - s_logger.debug("Removing the current security information."); + if (logger.isTraceEnabled()) + { + logger.trace("Removing the current security information for thread: " + Thread.currentThread().getName()); + } ContextHolder.setContext(null); InMemoryTicketComponentImpl.clearCurrentSecurityContext(); @@ -624,6 +671,10 @@ public class AuthenticationUtil implements InitializingBean threadLocalRunAsAuthenticationStack.get().push(originalRunAsAuthentication); threadLocalTenantDomainStack.get().push(TenantContextHolder.getTenantDomain()); + if (logger.isTraceEnabled()) + { + logger.trace("Pushed authentication in thread: " + Thread.currentThread().getName()); + } } /** @@ -646,6 +697,10 @@ public class AuthenticationUtil implements InitializingBean String originalTenantDomain = threadLocalTenantDomainStack.get().pop(); TenantContextHolder.setTenantDomain(originalTenantDomain); + if (logger.isTraceEnabled()) + { + logger.trace("Popped authentication in thread: " + Thread.currentThread().getName()); + } } /** @@ -653,12 +708,12 @@ public class AuthenticationUtil implements InitializingBean */ public static void logAuthenticatedUsers() { - if (s_logger.isDebugEnabled()) + if (logger.isDebugEnabled()) { - s_logger.debug( + logger.debug( "Authentication: \n" + - " Fully authenticated: " + AuthenticationUtil.getFullyAuthenticatedUser() + "\n" + - " Run as: " + AuthenticationUtil.getRunAsUser()); + " Fully authenticated: " + maskUsername(getFullyAuthenticatedUser()) + "\n" + + " Run as: " + maskUsername(getRunAsUser())); } } @@ -675,16 +730,16 @@ public class AuthenticationUtil implements InitializingBean final String tenantDomain = userTenant.getSecond(); if (! TenantService.DEFAULT_DOMAIN.equals(tenantDomain)) { - NDC.push("Tenant:" +tenantDomain + " User:" + userName); + NDC.push("Tenant:" +tenantDomain + " User:" + maskUsername(userName)); } else { - NDC.push("User:" + userName); + NDC.push("User:" + maskUsername(userName)); } } else { - NDC.push("User:" + userNameIn); + NDC.push("User:" + maskUsername(userNameIn)); } } } @@ -711,10 +766,10 @@ public class AuthenticationUtil implements InitializingBean { throw new AlfrescoRuntimeException("Unexpected tenant: "+tenantDomain+" (contains @)"); } - - if (s_logger.isDebugEnabled()) + + if (logger.isDebugEnabled()) { - s_logger.debug("Tenant domain implied: userName="+userName+", tenantDomain="+tenantDomain); + logger.debug("Tenant domain implied: userName=" + maskUsername(userName) + ", tenantDomain=" + tenantDomain); } } } diff --git a/src/main/java/org/alfresco/repo/security/authentication/InMemoryTicketComponentImpl.java b/src/main/java/org/alfresco/repo/security/authentication/InMemoryTicketComponentImpl.java index 1c52e6f056..a50002b00d 100644 --- a/src/main/java/org/alfresco/repo/security/authentication/InMemoryTicketComponentImpl.java +++ b/src/main/java/org/alfresco/repo/security/authentication/InMemoryTicketComponentImpl.java @@ -53,7 +53,7 @@ public class InMemoryTicketComponentImpl implements TicketComponent */ public static final String GRANTED_AUTHORITY_TICKET_PREFIX = "TICKET_"; - Log logger = LogFactory.getLog(getClass()); + private static Log logger = LogFactory.getLog(InMemoryTicketComponentImpl.class); private static ThreadLocal currentTicket = new ThreadLocal(); private boolean ticketsExpire; @@ -157,6 +157,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent String ticketString = GRANTED_AUTHORITY_TICKET_PREFIX + ticket.getTicketId(); currentTicket.set(ticketString); + if (logger.isTraceEnabled()) + { + logger.trace("Setting the current ticket for this thread: " + Thread.currentThread().getName() + " to: " + ticketString); + } return ticketString; } @@ -187,16 +191,30 @@ public class InMemoryTicketComponentImpl implements TicketComponent @Override public String validateTicket(String ticketString) throws AuthenticationException { + if (logger.isTraceEnabled()) + { + logger.trace("Validating ticket: " + ticketString); + } String ticketKey = getTicketKey(ticketString); Ticket ticket = ticketsCache.get(ticketKey); if (ticket == null) { - throw new AuthenticationException("Missing ticket for " + ticketString); + final String msg = "Missing ticket for " + ticketString; + if (logger.isDebugEnabled()) + { + logger.debug(msg); + } + throw new AuthenticationException(msg); } Ticket newTicket = ticket.getNewEntry(); if (newTicket == null) { - throw new TicketExpiredException("Ticket expired for " + ticketString); + final String msg = "Ticket expired for " + ticketString; + if (logger.isDebugEnabled()) + { + logger.debug(msg); + } + throw new TicketExpiredException(msg); } if (oneOff) { @@ -208,6 +226,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent ticketsCache.put(ticketKey, newTicket); } currentTicket.set(ticketString); + if (logger.isTraceEnabled()) + { + logger.trace("Setting the current ticket for this thread: " + Thread.currentThread().getName() + " to: " + ticketString); + } return newTicket.getUserName(); } @@ -247,6 +269,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent @Override public void invalidateTicketById(String ticketString) { + if (logger.isTraceEnabled()) + { + logger.trace("Invalidate ticket: " + ticketString); + } String key = ticketString.substring(GRANTED_AUTHORITY_TICKET_PREFIX.length()); ticketsCache.remove(key); } @@ -296,6 +322,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent @Override public int invalidateTickets(boolean expiredOnly) { + if (logger.isTraceEnabled()) + { + logger.trace("Invalidate all tickets, expired only: " + expiredOnly); + } Date now = new Date(); int count = 0; if (!expiredOnly) @@ -345,6 +375,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent for (String id : toRemove) { ticketsCache.remove(id); + if (logger.isTraceEnabled()) + { + logger.trace("Invalidate ticket for username: " + AuthenticationUtil.maskUsername(userName) + " ticket: " + id); + } } } @@ -440,6 +474,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent } } this.ticketId = ticketId; + if (logger.isTraceEnabled()) + { + logger.trace("Creating new ticket for user:" + AuthenticationUtil.maskUsername(userName)); + } } private Ticket(ExpiryMode expires, Date expiryDate, String userName, Duration validDuration, String ticketId) @@ -451,6 +489,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent Duration tenPercent = validDuration.divide(10); this.testDuration = validDuration.subtract(tenPercent); this.ticketId = ticketId; + if (logger.isTraceEnabled()) + { + logger.trace("Creating new ticket for user:" + AuthenticationUtil.maskUsername(userName)); + } } boolean hasExpired(Date now) @@ -483,6 +525,10 @@ public class InMemoryTicketComponentImpl implements TicketComponent Duration remaining = new Duration(now, expiryDate); if(remaining.compareTo(testDuration) < 0) { + if (logger.isTraceEnabled()) + { + logger.trace("AFTER_INACTIVITY case, Creating new ticket based on the current one that expires at: " + expiryDate); + } return new Ticket(expires, Duration.add(now, validDuration), userName, validDuration, ticketId); } else @@ -575,7 +621,12 @@ public class InMemoryTicketComponentImpl implements TicketComponent public static void clearCurrentSecurityContext() { + String prevTicket = currentTicket.get(); currentTicket.set(null); + if (logger.isTraceEnabled()) + { + logger.trace("Clearing the current ticket for this thread: " + Thread.currentThread().getName() + " . Previous ticket was: " + prevTicket); + } } public enum ExpiryMode