Uploaded image for project: 'Service Packs and Hot Fixes'
  1. Service Packs and Hot Fixes
  2. MNT-16270

Audit logger org.alfresco.repo.audit.inbound fails to log inbound auditable values

    Details

    • Type: Bug
    • Status: Closed
    • Resolution: Fixed
    • Affects Version/s: 4.2.5, 5.0.3
    • Fix Version/s: 4.2.7, 5.0.4, 5.1.2
    • Component/s: Auditing
    • Labels:
      None
    • Environment:
      v4.2.5/5.0.3 Alfresco One

      Description

      Summary

      With just audit.enabled=true, and no audit application (ex. audit.alfresco-access) enabled, you can log the available inbound audit methods/values.

      This allows you to determine what inbound audit values are 'available' (not actually recorded without a audit application defining it to record) to create an audit application against.

      This is not working in v4.2.N, v5.0.N versions.

      Replication Steps

      • Install and startup Alfresco One v4.2.5 (or v5.0.3)
      • Using jconsole check the configurations under: MBeans (tab) > Alfresco > Configuration > Audit > Attributes. By default you should only see:
      audit.alfresco-access.enabled=false
audit.cmischangelog.enabled=false
audit.enable=true
audit.sync.enabled=true
audit.tagging.enabled=true
      • set the following logger to debug in jconsole "org.alfresco.repo.audit.inbound"
      • monitor catalina.out log
      • do anything on share ui from logging in to any action at all, example login 
        2016-05-09 12:56:42,855  DEBUG [repo.audit.inbound] [http-8080-7] 
Inbound audit values:
	/alfresco-api/pre/AuthenticationService/authenticateAsGuest/args=null
 2016-05-09 12:56:42,863  DEBUG [repo.audit.inbound] [http-8080-7] 
Inbound audit values:
	/alfresco-api/post/AuthenticationService/authenticateAsGuest/args=null
	/alfresco-api/post/AuthenticationService/authenticateAsGuest/no-error=null
 2016-05-09 12:56:42,886  DEBUG [repo.audit.inbound] [http-8080-7] 
Inbound audit values:
	/alfresco-api/pre/RepoAdminService/getRestrictions/args=null
 2016-05-09 12:56:42,886  DEBUG [repo.audit.inbound] [http-8080-7] 
Inbound audit values:
	/alfresco-api/post/RepoAdminService/getRestrictions/args=null
	/alfresco-api/post/RepoAdminService/getRestrictions/no-error=null
 2016-05-09 12:56:42,907  INFO  [web.site.EditionInterceptor] [http-8080-1] Successfully retrieved license information from Alfresco.
 2016-05-09 12:56:43,016  DEBUG [repo.audit.inbound] [http-8080-7] 
Inbound audit values:
	/alfresco-api/pre/FileFolderService/resolveNamePath/args/rootNodeRef=workspace://SpacesStore/8cd7bf99-2880-4264-94b1-19d2de2c9030
	/alfresco-api/pre/FileFolderService/resolveNamePath/args/pathElements=[configurations, slingshot.site.configuration.xml]
 2016-05-09 12:56:43,021  DEBUG [repo.audit.inbound] [defaultThreadPool1] 
Inbound audit values:
	/alfresco-api/post/FileFolderService/resolveNamePath/error=Folder not found:  
   Started at: 
      org.alfresco.repo.model.filefolder.FileFolderServiceImpl.resolveNamePath(FileFolderServiceImpl.java:1462)
      org.alfresco.repo.model.filefolder.FileFolderServiceImpl.resolveNamePath(FileFolderServiceImpl.java:1441)
      sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      java.lang.reflect.Method.invoke(Method.java:606)
      org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
      org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
      org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
      org.alfresco.repo.model.ml.MLContentInterceptor.invoke(MLContentInterceptor.java:125)
      org.springframework.aop.framework.Reflec
	/alfresco-api/post/FileFolderService/resolveNamePath/args/rootNodeRef=workspace://SpacesStore/8cd7bf99-2880-4264-94b1-19d2de2c9030
	/alfresco-api/post/FileFolderService/resolveNamePath/args/pathElements=[configurations, slingshot.site.configuration.xml]
 2016-05-09 12:56:43,025  DEBUG [repo.audit.inbound] [http-8080-7] 
Inbound audit values:
	/alfresco-api/pre/FileFolderService/resolveNamePath/args/rootNodeRef=workspace://SpacesStore/8cd7bf99-2880-4264-94b1-19d2de2c9030
	/alfresco-api/pre/FileFolderService/resolveNamePath/args/pathElements=[pages, site-index.xml]

. . .

 2016-05-09 12:57:09,705  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/post/NodeService/getProperties/no-error=null
	/alfresco-api/post/NodeService/getProperties/args/nodeRef=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/post/NodeService/getProperties/result={{http://www.alfresco.org/model/content/1.0}name=53223edb-476a-499c-b5cd-bbd326585268, {http://www.alfresco.org/model/system/1.0}node-dbid=29, {http://www.alfresco.org/model/content/1.0}organizationId=, {http://www.alfresco.org/model/content/1.0}email=admin@alfresco.com, {http://www.alfresco.org/model/system/1.0}store-identifier=SpacesStore, {http://www.alfresco.org/model/system/1.0}locale=en_US, {http://www.alfresco.org/model/content/1.0}homeFolderProvider=bootstrapHomeFolderProvider, {http://www.alfresco.org/model/content/1.0}sizeCurrent=null, {http://www.alfresco.org/model/content/1.0}userName=admin, {http://www.alfresco.org/model/content/1.0}owner=admin, {http://www.alfresco.org/model/system/1.0}node-uuid=53223edb-476a-499c-b5cd-bbd326585268, {http://www.alfresco.org/model/content/1.0}lastName=, {http://www.alfresco.org/model/system/1.0}store-protocol=workspace, {http://www.alfresco.org/model/content/1.0}firstName=Administrator, {http://www.alfresco.org/model/content/1.0}homeFolder=workspace://SpacesStore/326e347d-9fa8-4445-b21f-e784e6af9619}
 2016-05-09 12:57:09,706  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/pre/PersonService/getPerson/args/userName=admin
 2016-05-09 12:57:09,706  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/post/PersonService/getPerson/no-error=null
	/alfresco-api/post/PersonService/getPerson/result=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/post/PersonService/getPerson/args/userName=admin
 2016-05-09 12:57:09,706  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/pre/NodeService/hasAspect/args/nodeRef=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/pre/NodeService/hasAspect/args/aspectTypeQName={http://www.alfresco.org/model/content/1.0}preferences
 2016-05-09 12:57:09,707  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/post/NodeService/hasAspect/args/aspectTypeQName={http://www.alfresco.org/model/content/1.0}preferences
	/alfresco-api/post/NodeService/hasAspect/no-error=null
	/alfresco-api/post/NodeService/hasAspect/args/nodeRef=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/post/NodeService/hasAspect/result=false
 2016-05-09 12:57:09,707  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/pre/PersonService/getPerson/args/userName=admin
 2016-05-09 12:57:09,708  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/post/PersonService/getPerson/no-error=null
	/alfresco-api/post/PersonService/getPerson/result=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/post/PersonService/getPerson/args/userName=admin
 2016-05-09 12:57:09,708  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/pre/NodeService/hasAspect/args/nodeRef=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/pre/NodeService/hasAspect/args/aspectTypeQName={http://www.alfresco.org/model/content/1.0}preferences
 2016-05-09 12:57:09,708  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/post/NodeService/hasAspect/args/aspectTypeQName={http://www.alfresco.org/model/content/1.0}preferences
	/alfresco-api/post/NodeService/hasAspect/no-error=null
	/alfresco-api/post/NodeService/hasAspect/args/nodeRef=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/post/NodeService/hasAspect/result=false
 2016-05-09 12:57:09,715  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/pre/SearchService/query/args=null
 2016-05-09 12:57:09,805  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/pre/AuthenticationService/validate/args=null
 2016-05-09 12:57:09,805  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/post/AuthenticationService/validate/args=null
	/alfresco-api/post/AuthenticationService/validate/no-error=null
 2016-05-09 12:57:09,806  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/pre/AuthorityService/isGuestAuthority/args/authorityName=admin
 2016-05-09 12:57:09,807  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/post/AuthorityService/isGuestAuthority/no-error=null
	/alfresco-api/post/AuthorityService/isGuestAuthority/args/authorityName=admin
	/alfresco-api/post/AuthorityService/isGuestAuthority/result=false
 2016-05-09 12:57:09,814  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/pre/AuthorityService/isAdminAuthority/args/authorityName=admin
 2016-05-09 12:57:09,815  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/post/AuthorityService/isAdminAuthority/no-error=null
	/alfresco-api/post/AuthorityService/isAdminAuthority/args/authorityName=admin
	/alfresco-api/post/AuthorityService/isAdminAuthority/result=true
 2016-05-09 12:57:09,826  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/pre/AuthenticationService/validate/args=null
 2016-05-09 12:57:09,826  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/post/AuthenticationService/validate/args=null
	/alfresco-api/post/AuthenticationService/validate/no-error=null
 2016-05-09 12:57:09,827  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/pre/AuthorityService/isGuestAuthority/args/authorityName=admin
 2016-05-09 12:57:09,828  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/post/AuthorityService/isGuestAuthority/no-error=null
	/alfresco-api/post/AuthorityService/isGuestAuthority/args/authorityName=admin
	/alfresco-api/post/AuthorityService/isGuestAuthority/result=false
 2016-05-09 12:57:09,832  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/pre/NodeService/getProperties/args/nodeRef=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
 2016-05-09 12:57:09,832  DEBUG [repo.audit.inbound] [http-8080-9] 
Inbound audit values:
	/alfresco-api/post/NodeService/getProperties/no-error=null
	/alfresco-api/post/NodeService/getProperties/args/nodeRef=workspace://SpacesStore/53223edb-476a-499c-b5cd-bbd326585268
	/alfresco-api/post/NodeService/getProperties/result={{http://www.alfresco.org/model/content/1.0}name=53223edb-476a-499c-b5cd-bbd326585268, {http://www.alfresco.org/model/system/1.0}node-dbid=29, {http://www.alfresco.org/model/content/1.0}organizationId=, {http://www.alfresco.org/model/content/1.0}email=admin@alfresco.com, {http://www.alfresco.org/model/system/1.0}store-identifier=SpacesStore, {http://www.alfresco.org/model/system/1.0}locale=en_US, {http://www.alfresco.org/model/content/1.0}homeFolderProvider=bootstrapHomeFolderProvider, {http://www.alfresco.org/model/content/1.0}sizeCurrent=null, {http://www.alfresco.org/model/content/1.0}userName=admin, {http://www.alfresco.org/model/content/1.0}owner=admin, {http://www.alfresco.org/model/system/1.0}node-uuid=53223edb-476a-499c-b5cd-bbd326585268, {http://www.alfresco.org/model/content/1.0}lastName=, {http://www.alfresco.org/model/system/1.0}store-protocol=workspace, {http://www.alfresco.org/model/content/1.0}firstName=Administrator, {http://www.alfresco.org/model/content/1.0}homeFolder=workspace://SpacesStore/326e347d-9fa8-4445-b21f-e784e6af9619}
 2016-05-09 12:57:10,043  DEBUG [repo.audit.inbound] [http-8080-8] 
Inbound audit values:
	/alfresco-api/post/SearchService/query/args=null
	/alfresco-api/post/SearchService/query/no-error=null

      Expected Behaviour

      • when setting org.alfresco.repo.audit.inbound=debug, you should see all the auditable method calls generate in the logs, regardless of any audit applications being enabled.

      Actual Behaviour

      • when setting the org.alfresco.repo.audit.inbound=debug, you do not see any logging of auditable method calls generated in the logs, you must enable audit.alfresco-access.enabled=true (the ootb audit application) to get inbound logging generates

      Additional Information

      • Tested on v4.2.5, v5.0.3 Alfresco One in comparison to v4.1.5 Alfresco One, sometime since v4.1 SP this is no longer logging as needed.
      • Without this logging you must enable an audit application ex. (aflresco-access) and you will only see the audited and recorded data for what is defined in that application

      This logger was extremely helpful when defining a custom audit application to fit your needs and when debugging auditing issues.
      Full example of what would normally log on a login action in the UI is attached.

        Attachments

          Issue Links

          is related to by

          Service Pack Request - MNT-16748 Failing to extract auditing entries from SearchService (eg. using Share) or CMISQueryService

          • Closed

            Structure

              Activity

                People

                • Assignee:
                  closedbugs Closed Bugs (Inactive)
                  Reporter:
                  jsoria Jennie Soria [X] (Inactive)
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  6 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved:

                    Time Tracking

                    Estimated:
                    Original Estimate - Not Specified
                    Not Specified
                    Remaining:
                    Remaining Estimate - 0 minutes
                    0m
                    Logged:
                    Time Spent - 2 days, 1 hour, 30 minutes
                    2d 1h 30m

                      Structure Helper Panel