James Server
  1. James Server
  2. JAMES-269

AvalonMailRepository emits spurious "so we're deleting it... good riddance" messages due to synchronization

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Trivial Trivial
    • Resolution: Fixed
    • Affects Version/s: 2.0a3, 2.1.3, 2.2.0
    • Fix Version/s: 2.2.0
    • Labels:
      None

      Description

      If you use AvalonMailRepository, especially if you use AvalonSpoolRepository, and you have a lot of active threads, you are likely to see quite a few:

      ERROR mailstore: Exception retrieving mail: java.lang.RuntimeException: Exception caught while retrieving an object, cause: java.io.FileNotFoundException: /path/xxx.Repository.FileObjectStore (No such file or directory), so we're deleting it... good riddance!

      People have seen, and asked, about this in the past, so I am going to document why this happens:

      AvalonSpoolRepository.accept() clones the key set and iterates over it. That method is synchronized, but remove(String key) is not. So one thread starts running in accept, clones the key set, and starts iterating over it. Meanwhile, another thread finishes processing that message and decides to remove it. Since remove is not synchronized, the file is removed from the repository and the live key set, but the key is still present in the cloned key set, and if the accept() method tries to retrieve(String) that message, it will find that it is removed.

      We could synchronize remove(String), but it does not appear that there is any point to doing so, and why would we want to hold up removing a message while waiting for another thread to find a message to process?

      The same situation occurs in the JDBC repository, and is logged at debug level rather than error level. AvalonMailRepository should also have the logging level changed.

        Activity

        Noel J. Bergman created issue -
        Hide
        Noel J. Bergman added a comment -

        Changed log level to debug.

        Show
        Noel J. Bergman added a comment - Changed log level to debug.
        Noel J. Bergman made changes -
        Field Original Value New Value
        Status Open [ 1 ] Closed [ 6 ]
        Resolution Fixed [ 1 ]
        Noel J. Bergman made changes -
        Resolution Fixed [ 1 ]
        Status Closed [ 6 ] Reopened [ 4 ]
        Noel J. Bergman made changes -
        Fix Version/s 2.2.0RC1 [ 10689 ]
        Fix Version/s 2.2.0RC2 [ 10700 ]
        Resolution Fixed [ 1 ]
        Status Reopened [ 4 ] Closed [ 6 ]
        Mark Thomas made changes -
        Workflow jira [ 31109 ] Default workflow, editable Closed status [ 12566750 ]
        Mark Thomas made changes -
        Workflow Default workflow, editable Closed status [ 12566750 ] jira [ 12581863 ]
        Transition Time In Source Status Execution Times Last Executer Last Execution Date
        Open Open Closed Closed
        4m 38s 1 Noel J. Bergman 22/Apr/04 02:49
        Closed Closed Reopened Reopened
        23m 49s 1 Noel J. Bergman 22/Apr/04 03:13
        Reopened Reopened Closed Closed
        20s 1 Noel J. Bergman 22/Apr/04 03:13

          People

          • Assignee:
            Unassigned
            Reporter:
            Noel J. Bergman
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development