Uploaded image for project: 'Alfresco One Platform'
  1. Alfresco One Platform
  2. ACE-5939

Alfresco Shared File Store Throws misleading errors when multiple instances are running

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Done
    • Affects Version/s: 6.1
    • Fix Version/s: 6.1
    • Component/s: Repository
    • Labels:
    • Environment:
      docker

      Description

      [Summary]

      When using multiple instances of the alfresco shared file store running against a single drive the CleanupScheduler job throws errors of files not found because other instances might already have cleaned up the data.

      [Steps to reproduce]

      • Setup a server machine with docker and docker-compose
      • Use the attached docker-compose file to start the test setup since it will start 2 containers with alfresco shared file store and one with a shared storage.

      docker-compose up

      Note that the frequency on which the cleanup job runs has been changed to run every minute.

      • Using another terminal window attach to one of the shared-file-store containers with

      docker exec -it <ID_CONTAINER> bash

      • In the container navigate to the folder /tmp/Alfresco/sfs
      • Create about 10,000 (or more) files in this folder
      • Monitor the logs for the shared-file-store containers and let the cleanup job run a few times

      [Expected behaviour]

      • The clean up completes without misleading errors

      [Observed behaviour]

      • The cleanup job runs in both nodes and eventually one of the nodes throws an exception because it couldn't clean up one of the files

       

      shared-file-store_1 | 2018-12-13 15:54:18.752 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Cleanup process started at: 1544716458751
      shared-file-store_1 | 2018-12-13 15:54:18.752 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Scheduler id: e61bbbef-abd1-4629-80ff-464859acaf3f
      shared-file-store-1_1 | 2018-12-13 15:54:18.772 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Cleanup process started at: 1544716458772
      shared-file-store-1_1 | 2018-12-13 15:54:18.772 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Scheduler id: db900bf7-87ac-45d6-bdfe-f646f2638c84
      shared-file-store-1_1 | java.nio.file.NoSuchFileException: /tmp/Alfresco/sfs/afile_6089.txt
      shared-file-store-1_1 | at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
      shared-file-store-1_1 | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
      shared-file-store-1_1 | at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
      shared-file-store-1_1 | at sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55)
      shared-file-store-1_1 | at sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:144)
      shared-file-store-1_1 | at sun.nio.fs.LinuxFileSystemProvider.readAttributes(LinuxFileSystemProvider.java:99)
      shared-file-store-1_1 | at java.nio.file.Files.readAttributes(Files.java:1737)
      shared-file-store-1_1 | at java.nio.file.FileTreeWalker.getAttributes(FileTreeWalker.java:219)
      shared-file-store-1_1 | at java.nio.file.FileTreeWalker.visit(FileTreeWalker.java:276)
      shared-file-store-1_1 | at java.nio.file.FileTreeWalker.next(FileTreeWalker.java:372)
      shared-file-store-1_1 | at java.nio.file.Files.walkFileTree(Files.java:2706)
      shared-file-store-1_1 | at java.nio.file.Files.walkFileTree(Files.java:2742)
      shared-file-store-1_1 | at org.alfresco.store.CleanupScheduler.clean(CleanupScheduler.java:166)
      shared-file-store-1_1 | at org.alfresco.store.CleanupScheduler.cleanUpTempContent(CleanupScheduler.java:145)
      shared-file-store-1_1 | at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      shared-file-store-1_1 | at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      shared-file-store-1_1 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      shared-file-store-1_1 | at java.lang.reflect.Method.invoke(Method.java:498)
      shared-file-store-1_1 | at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84)
      shared-file-store-1_1 | at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
      shared-file-store-1_1 | at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      shared-file-store-1_1 | at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
      shared-file-store-1_1 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
      shared-file-store-1_1 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
      shared-file-store-1_1 | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      shared-file-store-1_1 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      shared-file-store-1_1 | at java.lang.Thread.run(Thread.java:748)
      shared-file-store-1_1 | 2018-12-13 15:54:18.774 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Cleanup Duration: 2 ms
      shared-file-store-1_1 | 2018-12-13 15:54:18.774 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Next cleanup process scheduled at: 1544716518774
      shared-file-store_1 | 2018-12-13 15:54:18.805 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Scheduler removed 10000 files.
      shared-file-store_1 | 2018-12-13 15:54:18.805 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Size of removed content: 1 MB
      shared-file-store_1 | 2018-12-13 15:54:18.805 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Scheduler removed 10000 files.
      shared-file-store_1 | 2018-12-13 15:54:18.805 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Size of removed content: 1 MB
      shared-file-store_1 | 2018-12-13 15:54:18.805 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Cleanup Duration: 54 ms
      shared-file-store_1 | 2018-12-13 15:54:18.805 INFO 1 --- [pool-1-thread-1] org.alfresco.store.CleanupScheduler : Next cleanup process scheduled at: 1544716518805

        Attachments

          Issue Links

            Structure

              Activity

                People

                • Assignee:
                  closedissues Closed Issues
                  Reporter:
                  jportillo Jose Portillo
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  6 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved:

                    Structure Helper Panel