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

EagerContentStoreCleaner job not working correctly using Cryptodoc contentstore encryption

    Details

    • Type: Service Pack Request
    • Status: Closed (View Workflow)
    • Resolution: Fixed
    • Affects Version/s: 5.0.2
    • Fix Version/s: 5.0.4
    • Component/s: Content Encryption
    • Labels:
      None
    • Environment:
      Alfresco One 5.0.2

      Description

      [Summary]
      Using Crpytodoc contentstore encryption, the EagerContentStoreCleaner job is not running properly. There are related error messages and orphaned nodes are deleted from contentstore but not moved to contentstore.deleted.

      [Steps to reproduce]
      1. Setup Alfresco 5.0.2 with Cryptodoc contentstore encryption(see http://docs.alfresco.com/5.0/tasks/encrypted-amp-install.html)
      a) Have a license which allows contentstore encryption
      b) Generate a content encryption key named key.jks at a location of your choice. I used keytool

      keytool -genkey -alias key1 -keyalg RSA -keystore /opt/encryptKeystore/key.jks -keysize 2048
      

      c) In alfresco-global.properties setup encryption:

      filecontentstore.subsystem.name=encryptedContentStore
      cryptodoc.jce.keystore.path=/opt/encryptKeystore/key.jks
      cryptodoc.jce.keystore.password=alfresco
      cryptodoc.jce.key.aliases=key1
      cryptodoc.jce.key.passwords=alfresco
      cryptodoc.jce.keygen.defaultSymmetricKeySize=128
      

      NOTE: Use path, key alias and key/keystore password as specified while key generation.
      2. In alfresco┬┤s log4j.properties set:

      log4j.logger.org.alfresco.repo.content.cleanup=DEBUG

      3. Startup the Alfresco instance and monitor the log for errors.
      4. Via Share, create a test document in the repository as admin
      5. Get the content url for this document using node browser and note it somewhere.
      6. Delete the document via the delete action.
      7. Also delete that document from user profile => trashcan.
      8. Stop the server.
      9. Change the server date to one month in the future to skip the default 14 orphan protect days. Or set the "system.content.orphanProtectDay" property lower in alfresco-global.properties.
      10. Start the server again and monitor the log.
      11. Via Jconsole trigger the EagerContentStoreCleaner job:
      MBeans->Alfresco->Schedule->DEFAULT->MonitoredCronTrigger->contentStoreCleanerTrigger->Operations->executeNow)

      [Expected behaviour]
      As with the deletion from trashcan, the content_url of the deleted document was marked as orphan, the related bin file should not be present in the contentstore.deleted content store. There should be no exceptions relating to the EagerContentStoreCleaner.

      Note: for testing purposes, it may be easier to start with a clean system (i.e. empty deleted content store), run through the steps above, and then check the deleted content store. There should be no entries in there if the encrypted content store is enabled.

      [Current behaviour]
      There is an error related to the content_url noted in step 5:

      2016-04-17 19:04:27,695  DEBUG [content.cleanup.ContentStoreCleaner] [DefaultScheduler_Worker-6] Content store cleanup started.
      2016-04-17 19:04:27,739  ERROR [content.cleanup.EagerContentStoreCleaner] [DefaultScheduler_Worker-6] Content deletion listener failed: 
         URL:    store://2016/3/17/17/59/d530b53a-33e9-4bd0-9f4e-63a75a0aee72.bin
         Source: org.alfresco.enterprise.repo.content.cryptodoc.impl.CryptoContentStore@78d8af0e
       org.alfresco.error.AlfrescoRuntimeException: 03170008 Content url store://2016/3/17/17/59/d530b53a-33e9-4bd0-9f4e-63a75a0aee72.bin is not known
      	at org.alfresco.enterprise.repo.content.cryptodoc.impl.CryptoContentStore.getContentUrlKey(CryptoContentStore.java:225)
      	at org.alfresco.enterprise.repo.content.cryptodoc.impl.CryptoContentStore.getReader(CryptoContentStore.java:249)
      	at sun.reflect.GeneratedMethodAccessor391.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:483)
      	at org.alfresco.repo.management.subsystems.SubsystemProxyFactory$1.invoke(SubsystemProxyFactory.java:72)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
      	at org.alfresco.repo.management.subsystems.CryptodocSubsystemProxyFactory$1.invoke(CryptodocSubsystemProxyFactory.java:53)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
      	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
      	at com.sun.proxy.$Proxy19.getReader(Unknown Source)
      	at org.alfresco.repo.content.cleanup.DeletedContentBackupCleanerListener.beforeDelete(DeletedContentBackupCleanerListener.java:60)
      	at org.alfresco.repo.content.cleanup.EagerContentStoreCleaner.deleteFromStores(EagerContentStoreCleaner.java:282)
      	at org.alfresco.repo.content.cleanup.EagerContentStoreCleaner.deleteFromStores(EagerContentStoreCleaner.java:261)
      	at org.alfresco.repo.content.cleanup.ContentStoreCleaner.cleanBatch(ContentStoreCleaner.java:400)
      	at org.alfresco.repo.content.cleanup.ContentStoreCleaner.access$000(ContentStoreCleaner.java:75)
      	at org.alfresco.repo.content.cleanup.ContentStoreCleaner$1.execute(ContentStoreCleaner.java:336)
      	at org.alfresco.repo.content.cleanup.ContentStoreCleaner$1.execute(ContentStoreCleaner.java:333)
      	at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:454)
      	at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:323)
      	at org.alfresco.repo.content.cleanup.ContentStoreCleaner.executeInternal(ContentStoreCleaner.java:342)
      	at org.alfresco.repo.content.cleanup.ContentStoreCleaner.execute(ContentStoreCleaner.java:299)
      	at org.alfresco.repo.content.cleanup.ContentStoreCleanupJob.execute(ContentStoreCleanupJob.java:58)
      	at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
      	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:563)
      2016-04-17 19:04:27,744  DEBUG [content.cleanup.ContentStoreCleaner] [DefaultScheduler_Worker-6]    Removed orphaned content URLs up orphan time Thu Jan 01 01:00:00 CET 1970
      2016-04-17 19:04:27,746  DEBUG [content.cleanup.ContentStoreCleaner] [DefaultScheduler_Worker-6]    Content store cleanup completed.
      

      The bin file is deleted from contentstore, but not found in contentstore.deleted afterwards.

      [Supporting evidence]

      • Customer reported issue for Alfresco 5.0.1 and I could reproduce it with Alfresco 5.0.1 and latest service pack 5.0.2
      • Reviewing EagerContentStoreCleaner code I see it is going through all Stores (e.g. file contentstore, crpyto contentstore, etc), if store is supporting content URLs and writable:
        private boolean deleteFromStores(String contentUrl, boolean callListeners)
        {
        int deleted = 0;
        for (ContentStore store : stores)
        {
        // Bypass if the store is read-only or doesn't support the URL
        if (!store.isWriteSupported() || !store.isContentUrlSupported(contentUrl))
        {
        continue;
        }
        if (callListeners)
        {
        // Call listeners
        for (ContentStoreCleanerListener listener : listeners)
        {
        try
        {
        // Since we are in post-commit, we do best-effort
        listener.beforeDelete(store, contentUrl);
        }
        catch (Throwable e)
        {
        logger.error(
        "Content deletion listener failed: \n" +
        " URL: " + contentUrl + "\n" +
        " Source: " + store,
        e);
        }
        
      • My guess is, that the code should not be executed on the crypto content store, as it is only a virtual store to encrypt/decrpyt content from the file store and the content_url is only pointing to the file contentstore and not this virtual store.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                closedbugs Closed Bugs
                Reporter:
                dkoch Dennis Koch
              • Votes:
                1 Vote for this issue
                Watchers:
                7 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 - 4 days, 6 hours, 5 minutes
                  4d 6h 5m