Wired AuditMethodInterceptor into new audit framework

- Two new repo properties to control auditing:
     audit.enabled=false
     audit.useNewConfig=false
 - Auditing was enabled by default, but it is not enabled any more!
   The property has to be set in alfresco-global.properties
 - Unit tests for auditing successful and failed authentication attempts


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

config/alfresco/public-services-context.xml

@@ -31,11 +31,20 @@
     <!-- AuditMethodInterceptor -->
 
     <bean id="AuditMethodInterceptor" class="org.alfresco.repo.audit.AuditMethodInterceptor">
+        <property name="publicServiceIdentifier">
+            <ref bean="publicServiceIdentifier"/>
+        </property>
         <property name="auditComponent">
             <ref bean="auditComponent"/>
         </property>
-        <property name="disabled">
+        <property name="transactionService">
-            <value>false</value>
+            <ref bean="transactionService"/>
+        </property>
+        <property name="enabled">
+            <value>${audit.enabled}</value>
+        </property>
+        <property name="useNewConfig">
+            <value>${audit.useNewConfig}</value>
         </property>
     </bean>
 
@@ -567,36 +576,36 @@
                 <prop key="*">${server.transaction.mode.default}</prop>
             </props>
         </property>
-    </bean>
+    </bean>
-    
+    
     <!-- Content Usage Service -->
-    
+    
-    <bean id="ContentUsageService" class="org.springframework.aop.framework.ProxyFactoryBean">
+    <bean id="ContentUsageService" class="org.springframework.aop.framework.ProxyFactoryBean">
-        <property name="proxyInterfaces">
+        <property name="proxyInterfaces">
-            <value>org.alfresco.service.cmr.usage.ContentUsageService</value>
+            <value>org.alfresco.service.cmr.usage.ContentUsageService</value>
-        </property>
+        </property>
-        <property name="target">
+        <property name="target">
-            <ref bean="contentUsageImpl"/>
+            <ref bean="contentUsageImpl"/>
-        </property>
+        </property>
-        <property name="interceptorNames">
+        <property name="interceptorNames">
-            <list>
+            <list>
-                <idref local="ContenUsageService_transaction"/>
+                <idref local="ContenUsageService_transaction"/>
-                <idref local="AuditMethodInterceptor"/>
+                <idref local="AuditMethodInterceptor"/>
-                <idref local="exceptionTranslator"/>
+                <idref local="exceptionTranslator"/>
-                <idref bean="ContentUsageService_security"/>
+                <idref bean="ContentUsageService_security"/>
-            </list>
+            </list>
-        </property>
+        </property>
-    </bean>
+    </bean>
-    
+    
-    <bean id="ContenUsageService_transaction" class="org.springframework.transaction.interceptor.TransactionInterceptor">
+    <bean id="ContenUsageService_transaction" class="org.springframework.transaction.interceptor.TransactionInterceptor">
-        <property name="transactionManager">
+        <property name="transactionManager">
-            <ref bean="transactionManager"/>
+            <ref bean="transactionManager"/>
-        </property>
+        </property>
-        <property name="transactionAttributes">
+        <property name="transactionAttributes">
-            <props>
+            <props>
-                <prop key="*">${server.transaction.mode.default}</prop>
+                <prop key="*">${server.transaction.mode.default}</prop>
-            </props>
+            </props>
-        </property>
+        </property>
     </bean>
 
     <!-- Authentication Service -->

config/alfresco/repository.properties

@@ -204,6 +204,10 @@ db.pool.evict.validate=false
 db.pool.abandoned.detect=false
 db.pool.abandoned.time=300
 
+# Audit configuration
+audit.enabled=false
+audit.useNewConfig=false
+
 # Email configuration
 mail.host=
 mail.port=25

source/java/org/alfresco/repo/audit/AuditComponent.java

@@ -168,7 +168,8 @@ public interface AuditComponent
      * The return values reflect what was actually persisted and is controlled by the data extractors
      * defined in the audit configuration.
      * <p/>
-     * This is a read-write method.  Client code must wrap calls in the appropriate transactional wrappers.
+     * A new read-write transaction is started if there are values to write that there is not a viable
+     * transaction present.
      * 
      * @param rootPath          a base path of {@link AuditPath} key entries concatenated with the path separator
      *                          '/' ({@link AuditApplication#AUDIT_PATH_SEPARATOR})

source/java/org/alfresco/repo/audit/AuditComponentImpl.java

@@ -1040,7 +1040,6 @@ public class AuditComponentImpl implements AuditComponent
     public Map<String, Serializable> recordAuditValues(String rootPath, Map<String, Serializable> values)
     {
         ParameterCheck.mandatory("rootPath", rootPath);
-        AlfrescoTransactionSupport.checkTransactionReadState(true);
         AuditApplication.checkPathFormat(rootPath);
 
         if (values == null || values.isEmpty())
@@ -1058,8 +1057,41 @@ public class AuditComponentImpl implements AuditComponent
         
         // Translate the values map
         PathMapper pathMapper = auditModelRegistry.getAuditPathMapper();
-        Map<String, Serializable> mappedValues = pathMapper.convertMap(pathedValues);
+        final Map<String, Serializable> mappedValues = pathMapper.convertMap(pathedValues);
+        if (mappedValues.isEmpty())
+        {
+            return mappedValues;
+        }
         
+        // We have something to record.  Start a transaction, if necessary
+        TxnReadState txnState = AlfrescoTransactionSupport.getTransactionReadState();
+        switch (txnState)
+        {
+        case TXN_NONE:
+        case TXN_READ_ONLY:
+            // New transaction
+            RetryingTransactionCallback<Map<String, Serializable>> callback =
+                    new RetryingTransactionCallback<Map<String,Serializable>>()
+            {
+                public Map<String, Serializable> execute() throws Throwable
+                {
+                    return recordAuditValuesImpl(mappedValues);
+                }
+            };
+            return transactionService.getRetryingTransactionHelper().doInTransaction(callback, false, true);
+        case TXN_READ_WRITE:
+            return recordAuditValuesImpl(mappedValues);
+        default:
+            throw new IllegalStateException("Unknown txn state: " + txnState);
+        }
+    }
+    
+    /**
+     * {@inheritDoc}
+     * @since 3.2
+     */
+    public Map<String, Serializable> recordAuditValuesImpl(Map<String, Serializable> mappedValues)
+    {
         // Group the values by root path
         Map<String, Map<String, Serializable>> mappedValuesByRootKey = new HashMap<String, Map<String,Serializable>>();
         for (Map.Entry<String, Serializable> entry : mappedValues.entrySet())
@@ -1075,7 +1107,7 @@ public class AuditComponentImpl implements AuditComponent
             rootKeyMappedValues.put(path, entry.getValue());
         }
 
-        Map<String, Serializable> allAuditedValues = new HashMap<String, Serializable>(values.size()*2+1);
+        Map<String, Serializable> allAuditedValues = new HashMap<String, Serializable>(mappedValues.size()*2+1);
         // Now audit for each of the root keys
         for (Map.Entry<String, Map<String, Serializable>> entry : mappedValuesByRootKey.entrySet())
         {

source/java/org/alfresco/repo/audit/AuditComponentTest.java

@@ -26,9 +26,11 @@ package org.alfresco.repo.audit;
 
 import java.io.Serializable;
 import java.net.URL;
+import java.util.ArrayList;
 import java.util.Collections;
 import java.util.Date;
 import java.util.HashMap;
+import java.util.List;
 import java.util.Map;
 
 import junit.framework.TestCase;
@@ -36,14 +38,17 @@ import junit.framework.TestCase;
 import org.alfresco.repo.audit.model.AuditApplication;
 import org.alfresco.repo.audit.model.AuditModelException;
 import org.alfresco.repo.audit.model.AuditModelRegistry;
+import org.alfresco.repo.security.authentication.AuthenticationException;
 import org.alfresco.repo.security.authentication.AuthenticationUtil;
 import org.alfresco.repo.security.authentication.AuthenticationUtil.RunAsWork;
 import org.alfresco.repo.transaction.RetryingTransactionHelper.RetryingTransactionCallback;
 import org.alfresco.service.ServiceRegistry;
+import org.alfresco.service.cmr.audit.AuditService;
 import org.alfresco.service.cmr.audit.AuditService.AuditQueryCallback;
 import org.alfresco.service.cmr.repository.NodeRef;
 import org.alfresco.service.cmr.repository.NodeService;
 import org.alfresco.service.cmr.repository.StoreRef;
+import org.alfresco.service.cmr.security.AuthenticationService;
 import org.alfresco.service.transaction.TransactionService;
 import org.alfresco.util.ApplicationContextHelper;
 import org.alfresco.util.EqualsHelper;
@@ -66,6 +71,7 @@ public class AuditComponentTest extends TestCase
 {
     private static final String APPLICATION_TEST = "Alfresco Test";
     private static final String APPLICATION_ACTIONS_TEST = "Actions Test";
+    private static final String APPLICATION_API_TEST = "API Test";
     
     private static final Log logger = LogFactory.getLog(AuditComponentTest.class);
     
@@ -73,6 +79,7 @@ public class AuditComponentTest extends TestCase
     
     private AuditModelRegistry auditModelRegistry;
     private AuditComponent auditComponent;
+    private AuditService auditService;
     private ServiceRegistry serviceRegistry;
     private TransactionService transactionService;
     private NodeService nodeService;
@@ -86,6 +93,7 @@ public class AuditComponentTest extends TestCase
         auditModelRegistry = (AuditModelRegistry) ctx.getBean("auditModel.modelRegistry");
         auditComponent = (AuditComponent) ctx.getBean("auditComponent");
         serviceRegistry = (ServiceRegistry) ctx.getBean(ServiceRegistry.SERVICE_REGISTRY); 
+        auditService = serviceRegistry.getAuditService();
         transactionService = serviceRegistry.getTransactionService();
         nodeService = serviceRegistry.getNodeService();
         
@@ -132,15 +140,9 @@ public class AuditComponentTest extends TestCase
     
     public void testAuditWithBadPath() throws Exception
     {
-        try
+        // Should start an appropriate txn
-        {
+        auditComponent.recordAuditValues("/test", Collections.<String, Serializable>emptyMap());
-            auditComponent.recordAuditValues("/test", Collections.<String, Serializable>emptyMap());
+        
-            fail("Should fail due to lack of a transaction.");
-        }
-        catch (IllegalStateException e)
-        {
-            // Expected
-        }
         RetryingTransactionCallback<Void> testCallback = new RetryingTransactionCallback<Void>()
         {
             public Void execute() throws Throwable
@@ -436,4 +438,102 @@ public class AuditComponentTest extends TestCase
         };
         transactionService.getRetryingTransactionHelper().doInTransaction(disableAuditCallback, false);
     }
+    
+    public void testAuditAuthenticationService() throws Exception
+    {
+        final Map<String, Serializable> expected = new HashMap<String, Serializable>();
+        expected.put("/actions-test/actions/user", AuthenticationUtil.getFullyAuthenticatedUser());
+        expected.put("/actions-test/actions/context-node/noderef", nodeRef);
+        expected.put("/actions-test/actions/action-01/params/A/value", null);
+        expected.put("/actions-test/actions/action-01/params/B/value", null);
+        expected.put("/actions-test/actions/action-01/params/C/value", null);
+        
+        final List<Map<String, Serializable>> results = new ArrayList<Map<String,Serializable>>();
+        final StringBuilder sb = new StringBuilder();
+        AuditQueryCallback auditQueryCallback = new AuditQueryCallback()
+        {
+            public boolean handleAuditEntry(
+                    Long entryId,
+                    String applicationName,
+                    String user,
+                    long time,
+                    Map<String, Serializable> values)
+            {
+                if (logger.isDebugEnabled())
+                {
+                    logger.debug(
+                            "Audit Entry: " + applicationName + ", " + user + ", " + new Date(time) + "\n" +
+                            "   Data: " + values);
+                    results.add(values);
+                }
+                sb.append("Row: ")
+                  .append(entryId).append(" | ")
+                  .append(applicationName).append(" | ")
+                  .append(user).append(" | ")
+                  .append(new Date(time)).append(" | ")
+                  .append(values).append(" | ")
+                  .append("\n");
+                  ;
+                return true;
+            }
+        };
+        
+        auditService.clearAudit(APPLICATION_API_TEST);
+        results.clear();
+        sb.delete(0, sb.length());
+        auditService.auditQuery(auditQueryCallback, APPLICATION_API_TEST, null, null, null, -1);
+        logger.debug(sb.toString());
+        assertTrue("There should be no audit entries for the API test after a clear", results.isEmpty());
+        
+        final AuthenticationService authenticationService = serviceRegistry.getAuthenticationService();
+        // Create a good authentication
+        RunAsWork<Void> createAuthenticationWork = new RunAsWork<Void>()
+        {
+            public Void doWork() throws Exception
+            {
+                if (!authenticationService.authenticationExists(getName()))
+                {
+                    authenticationService.createAuthentication(getName(), getName().toCharArray());
+                }
+                return null;
+            }
+        };
+        AuthenticationUtil.runAs(createAuthenticationWork, AuthenticationUtil.getSystemUserName());
+        
+        // Clear everything out and do a successful authentication
+        auditService.clearAudit(APPLICATION_API_TEST);
+        try
+        {
+            AuthenticationUtil.pushAuthentication();
+            authenticationService.authenticate(getName(), getName().toCharArray());
+        }
+        finally
+        {
+            AuthenticationUtil.popAuthentication();
+        }
+        
+        // Check that the call was audited
+        results.clear();
+        sb.delete(0, sb.length());
+        auditService.auditQuery(auditQueryCallback, APPLICATION_API_TEST, null, null, null, -1);
+        logger.debug(sb.toString());
+        assertFalse("Did not get any audit results after successful login", results.isEmpty());
+
+        // Clear everything and check that unsuccessful authentication was audited
+        auditService.clearAudit(APPLICATION_API_TEST);
+        try
+        {
+            authenticationService.authenticate("banana", "****".toCharArray());
+            fail("Invalid authentication attempt should fail");
+        }
+        catch (AuthenticationException e)
+        {
+            // Expected
+        }
+        results.clear();
+        sb.delete(0, sb.length());
+        auditService.auditQuery(auditQueryCallback, APPLICATION_API_TEST, null, null, null, -1);
+        logger.debug(sb.toString());
+        assertFalse("Did not get any audit results after failed login", results.isEmpty());
+    }
 }

source/java/org/alfresco/repo/audit/AuditMethodInterceptor.java

@@ -24,33 +24,107 @@
  */
 package org.alfresco.repo.audit;
 
+import java.io.Serializable;
+import java.util.HashMap;
+import java.util.Map;
+
+import org.alfresco.error.StackTraceUtil;
+import org.alfresco.repo.audit.model.AuditApplication;
+import org.alfresco.repo.transaction.RetryingTransactionHelper.RetryingTransactionCallback;
+import org.alfresco.service.Auditable;
+import org.alfresco.service.cmr.repository.datatype.DefaultTypeConverter;
+import org.alfresco.service.cmr.repository.datatype.TypeConversionException;
+import org.alfresco.service.transaction.TransactionService;
 import org.aopalliance.intercept.MethodInterceptor;
 import org.aopalliance.intercept.MethodInvocation;
+import org.apache.commons.logging.Log;
+import org.apache.commons.logging.LogFactory;
 
 /** 
  * A method interceptor to wrap method invocations with auditing.
+ * <p/>
+ * <b><u>V3.2 Configuration</u>:</b>
+ * As of V3.2, the pre- and post-invocation values are passed to the audit component
+ * for processing.  Individual applications have to extract the desired audit values.
+ * Values are audited before and after the invocation so that applications that desire
+ * to extract derived data before the invocation can have a chance to do so; generally,
+ * however, the post-invocation values will be the most useful.
+ * <p/>
+ * The values passed to the audit component (assuming auditing is enabled and the
+ * new configuration is being used) are:
+ * <pre>
+ * /alfresco-api
+ *    /pre
+ *       /&lt;service&gt;
+ *          /&lt;method&gt;
+ *             /args
+ *                /&lt;arg-name&gt;=&lt;value&gt;
+ *                /&lt;arg-name&gt;=&lt;value&gt;
+ *                ...
+ *       /service
+ *    /post
+ *       /&lt;service&gt;
+ *          /&lt;method&gt;
+ *             /args
+ *                /&lt;arg-name&gt;=&lt;value&gt;
+ *                /&lt;arg-name&gt;=&lt;value&gt;
+ *                ...
+ *             /result=&lt;value&gt;
+ *             /error=&lt;value&gt;
  * 
- * A single instance is used to wrap all services. If the single instance is disabled
+ * </pre>
- * no auditing will be carried out and there will be minimal overhead. 
+ * Applications can remap the paths onto their configurations as appropriate.
+ * <p/>
+ * TODO: Audit configuration mapping needs to support conditionals
  * 
  * @author Andy Hind
+ * @author Derek Hulley
  */
 public class AuditMethodInterceptor implements MethodInterceptor
 {
-    //private static Log s_logger = LogFactory.getLog(AuditMethodInterceptor.class);
+    public static final String AUDIT_PATH_API_PRE = "/alfresco-api/pre";
+    public static final String AUDIT_PATH_API_POST = "/alfresco-api/post";
+    public static final String AUDIT_SNIPPET_ARGS = "/args";
+    public static final String AUDIT_SNIPPET_RESULT = "/result";
+    public static final String AUDIT_SNIPPET_ERROR = "/error";
+    
+    private static final Log logger = LogFactory.getLog(AuditMethodInterceptor.class);
 
+    private PublicServiceIdentifier publicServiceIdentifier;
     private AuditComponent auditComponent;
+    private TransactionService transactionService;
 
-    private boolean disabled = false;
+    private boolean enabled = false;
+    private boolean useNewConfig = false;
+    
+    private final ThreadLocal<Boolean> inAudit = new ThreadLocal<Boolean>();
     
     public AuditMethodInterceptor()
     {
         super();
     }
 
-    public void setDisabled(boolean disabled)
+    /**
+     * Enable or disable auditing at a high level (default: <b>false</b>)
+     */
+    public void setEnabled(boolean enabled)
     {
-        this.disabled = disabled;
+        this.enabled = enabled;
+    }
+
+    /**
+     * Use the new audit configuration (default: <b>false</b>)
+     * 
+     * @param useNewConfig              <tt>true</tt> to use the new audit configuration
+     */
+    public void setUseNewConfig(boolean useNewConfig)
+    {
+        this.useNewConfig = useNewConfig;
+    }
+
+    public void setPublicServiceIdentifier(PublicServiceIdentifier serviceIdentifier)
+    {
+        this.publicServiceIdentifier = serviceIdentifier;
     }
 
     public void setAuditComponent(AuditComponent auditComponent)
@@ -58,16 +132,302 @@ public class AuditMethodInterceptor implements MethodInterceptor
         this.auditComponent = auditComponent;
     }
 
+    public void setTransactionService(TransactionService transactionService)
+    {
+        this.transactionService = transactionService;
+    }
+
     public Object invoke(MethodInvocation mi) throws Throwable
     {
-        if(disabled)
+        if(!enabled)
         {
+            // No auditing
             return mi.proceed();
         }
+        else if (useNewConfig)
+        {
+            // New configuration to be used
+            return proceed(mi);
+        }
         else
         {
+            // Use previous configuration
             return auditComponent.audit(mi);
         }
         
     }
+    
+    /**
+     * Allow the given method invocation to proceed, auditing values before invocation and
+     * after returning or throwing.
+     * 
+     * @param mi                the invocation
+     * @return                  Returns the method return (if a value is not thrown)
+     * @throws Throwable        rethrows any exception generated by the invocation
+     * 
+     * @since 3.2
+     */
+    private Object proceed(MethodInvocation mi) throws Throwable
+    {
+        Auditable auditableDef = mi.getMethod().getAnnotation(Auditable.class);
+        if (auditableDef == null)
+        {
+            // No annotation, so just continue as normal
+            return mi.proceed();
+        }
+        
+        // First get the argument map, if present
+        Object[] args = mi.getArguments();
+        Map<String, Serializable> namedArguments = getInvocationArguments(auditableDef, args);
+        // Get the service name
+        String serviceName = publicServiceIdentifier.getPublicServiceName(mi);
+        if (serviceName == null)
+        {
+            // Not a public service
+            return mi.proceed();
+        }
+        String methodName = mi.getMethod().getName();
+        
+        // Are we in a nested audit
+        Boolean wasInAudit = inAudit.get();
+        // TODO: Need to make this configurable for the interceptor or a conditional mapping for audit
+        if (wasInAudit != null)
+        {
+            return mi.proceed();
+        }
+        // Record that we have entered an audit method
+        inAudit.set(Boolean.TRUE);
+        try
+        {
+            return proceedWithAudit(mi, auditableDef, serviceName, methodName, namedArguments);
+        }
+        finally
+        {
+            inAudit.set(wasInAudit);
+        }
+    }
+    
+    private Object proceedWithAudit(
+            MethodInvocation mi,
+            Auditable auditableDef,
+            String serviceName,
+            String methodName,
+            Map<String, Serializable> namedArguments) throws Throwable
+    {
+        try
+        {
+            auditInvocationBefore(serviceName, methodName, namedArguments);
+        }
+        catch (Throwable e)
+        {
+            // Failure to audit should not break the invocation
+            logger.error(
+                    "Failed to audit pre-invocation: \n" +
+                    "   Invocation: " + mi,
+                    e);
+        }
+        
+        // Execute the call
+        Object ret = null;
+        Throwable thrown = null;
+        try
+        {
+            ret = mi.proceed();
+        }
+        catch (Throwable e)
+        {
+            thrown = e;
+        }
+        
+        // We don't ALWAYS want to record the return value
+        Object auditRet = auditableDef.recordReturnedObject() ? ret : null;
+        try
+        {
+            auditInvocationAfter(serviceName, methodName, namedArguments, auditRet, thrown);
+        }
+        catch (Throwable e)
+        {
+            // Failure to audit should not break the invocation
+            logger.error(
+                    "Failed to audit post-invocation: \n" +
+                    "   Invocation: " + mi,
+                    e);
+        }
+        
+        // Done
+        if (thrown != null)
+        {
+            throw thrown;
+        }
+        else
+        {
+            return ret;
+        }
+    }
+    
+    /**
+     * @return                  Returns the arguments mapped by name
+     * 
+     * @since 3.2
+     */
+    private Map<String, Serializable> getInvocationArguments(Auditable auditableDef, Object[] args)
+    {
+        // Use the annotation to name the arguments
+        String[] params = auditableDef.parameters();
+        boolean[] recordable = auditableDef.recordable();
+        
+        Map<String, Serializable> namedArgs = new HashMap<String, Serializable>(args.length * 2);
+        for (int i = 0; i < args.length; i++)
+        {
+            if (i >= params.length)
+            {
+                // The name list is finished.  Unnamed arguments are not recorded.
+                break;
+            }
+            if (i < recordable.length)
+            {
+                // Arguments are recordable by default
+                if (!recordable[i])
+                {
+                    // Don't record the argument
+                    continue;
+                }
+            }
+            Serializable arg;
+            if (args[i] == null)
+            {
+                arg = null;
+            }
+            else if (args[i] instanceof Serializable)
+            {
+                arg = (Serializable) args[i];
+            }
+            else
+            {
+                // TODO: How to treat non-serializable args
+                // arg = args[i].toString();
+                try
+                {
+                    arg = DefaultTypeConverter.INSTANCE.convert(String.class, args[i]);
+                }
+                catch (TypeConversionException e)
+                {
+                    // No viable conversion
+                    continue;
+                }
+            }
+            // It is named and recordable
+            namedArgs.put(params[i], arg);
+        }
+        // Done
+        return namedArgs;
+    }
+    
+    /**
+     * Audit values before the invocation
+     * 
+     * @param serviceName       the service name
+     * @param methodName        the method name
+     * @param namedArguments    the named arguments passed to the invocation
+     * 
+     * @since 3.2
+     */
+    private void auditInvocationBefore(
+            final String serviceName,
+            final String methodName,
+            final Map<String, Serializable> namedArguments)
+    {
+        final String rootPath = AuditApplication.buildPath(AUDIT_PATH_API_PRE, serviceName, methodName, AUDIT_SNIPPET_ARGS);
+        
+        // Audit in a read-write txn
+        Map<String, Serializable> auditedData = auditComponent.recordAuditValues(rootPath, namedArguments);
+        // Done
+        if (logger.isDebugEnabled() && auditedData.size() > 0)
+        {
+            logger.debug(
+                    "Audited before invocation: \n" +
+                    "   Values: " + auditedData);
+        }
+    }
+    
+    /**
+     * Audit values after the invocation
+     * 
+     * @param serviceName       the service name
+     * @param methodName        the method name
+     * @param namedArguments    the named arguments passed to the invocation
+     * @param ret               the result of the execution (may be <tt>null</tt>)
+     * @param thrown            the error thrown by the invocation (may be <tt>null</tt>)
+     * 
+     * @since 3.2
+     */
+    private void auditInvocationAfter(
+            String serviceName, String methodName, Map<String, Serializable> namedArguments,
+            Object ret, Throwable thrown)
+    {
+        final String rootPath = AuditApplication.buildPath(AUDIT_PATH_API_POST, serviceName, methodName);
+        
+        final Map<String, Serializable> auditData = new HashMap<String, Serializable>(23);
+        for (Map.Entry<String, Serializable> entry : namedArguments.entrySet())
+        {
+            String argName = entry.getKey();
+            Serializable argValue = entry.getValue();
+            auditData.put(
+                    AuditApplication.buildPath(AUDIT_SNIPPET_ARGS, argName),
+                    argValue);
+        }
+        if (ret != null)
+        {
+            if (ret instanceof Serializable)
+            {
+                auditData.put(AUDIT_SNIPPET_RESULT, (Serializable) ret);
+            }
+            else
+            {
+                // TODO: How do we treat non-serializable return values
+                try
+                {
+                    ret = DefaultTypeConverter.INSTANCE.convert(String.class, ret);
+                    auditData.put(AUDIT_SNIPPET_RESULT, (String) ret);
+                }
+                catch (TypeConversionException e)
+                {
+                    // No viable conversion
+                }
+            }
+        }
+        Map<String, Serializable> auditedData;
+        if (thrown != null)
+        {
+            StringBuilder sb = new StringBuilder(1024);
+            StackTraceUtil.buildStackTrace(
+                    thrown.getMessage(), thrown.getStackTrace(), sb, Integer.MAX_VALUE);
+            auditData.put(AUDIT_SNIPPET_ERROR, sb.toString());
+            
+            // An exception will generally roll the current transaction back
+            RetryingTransactionCallback<Map<String, Serializable>> auditCallback =
+                    new RetryingTransactionCallback<Map<String, Serializable>>()
+            {
+                public Map<String, Serializable> execute() throws Throwable
+                {
+                    return auditComponent.recordAuditValues(rootPath, auditData);
+                }
+            };
+            auditedData = transactionService.getRetryingTransactionHelper().doInTransaction(auditCallback, false, true);
+        }
+        else
+        {
+            // The current transaction will be fine
+            auditedData = auditComponent.recordAuditValues(rootPath, auditData);
+        }
+        
+        // Done
+        if (logger.isDebugEnabled() && auditedData.size() > 0)
+        {
+            logger.debug(
+                    "Audited before invocation: \n" +
+                    (thrown == null ? "" : "   Exception: " + thrown.getMessage() + "\n") +
+                    "   Values: " + auditedData);
+        }
+    }
 }

source/java/org/alfresco/repo/domain/audit/AbstractAuditDAOImpl.java

@@ -411,7 +411,10 @@ public abstract class AbstractAuditDAOImpl implements AuditDAO
             }
             // Resolve the application and username
             String auditAppName = (String) propertyValueDAO.getPropertyValueById(row.getAuditAppNameId()).getSecond();
-            String auditUser = (String) propertyValueDAO.getPropertyValueById(row.getAuditUserId()).getSecond();
+            Long auditUserId = row.getAuditUserId();
+            String auditUser = auditUserId == null
+                    ? null
+                    : (String) propertyValueDAO.getPropertyValueById(auditUserId).getSecond();
             
             more = callback.handleAuditEntry(
                     row.getAuditEntryId(),

source/test-resources/alfresco/audit/alfresco-audit-test.xml

@@ -24,6 +24,7 @@
         <PathMap source="/test/one.one/two.two" target="/test/1.1/2.2"/>
         <PathMap source="/actions-test" target="/actions-test"/>
         <PathMap source="/actions-test/actions/action-01-mapped" target="/actions-test/actions/action-01"/>
+        <PathMap source="/alfresco-api" target="/api-test"/>
     </PathMappings>
 
     <Application name="Alfresco Test" key="test">
@@ -95,4 +96,23 @@
         </AuditPath>
     </Application>
 
+    <Application name="API Test" key="api-test">
+        <AuditPath key="post">
+	        <AuditPath key="AuthenticationService">
+	            <AuditPath key="authenticate">
+	                <AuditPath key="args">
+	                    <AuditPath key="userName">
+	                        <RecordValue key="value" dataExtractor="simpleValue"/>
+	                    </AuditPath>
+	                </AuditPath>
+	                <AuditPath key="error">
+	                    <AuditPath key="userName">
+	                        <RecordValue key="value" dataExtractor="simpleValue"/>
+	                    </AuditPath>
+	                </AuditPath>
+	            </AuditPath>
+	        </AuditPath>
+	    </AuditPath>
+    </Application>
+
 </Audit>