Investigate why TimeBasedDirectoryCleaner counts too many deletes on MacOS

[chrisrohr]

No description provided.

[sleberknight]

See the testScheduleCleanup_WithScheduledExecutor_UsingMultipleConcurrentCleaners_IntegrationTest which is @EnabledOnOs(OS.LINUX)

[sleberknight]

To clarify, when run on macOS (tested on Catalina and Big Sur), we see more deletes than the total number of directories created.

I modified waitUntilReachExpectedDeleteCount as follows and each time I run the tests I get slightly different results.

    private void waitUntilReachExpectedDeleteCount(TimeBasedDirectoryCleaner cleaner1,
                                                   TimeBasedDirectoryCleaner cleaner2,
                                                   int expectedDeleteCount) {
        await().atMost(TEN_SECONDS).until(() -> {
            long aggregateDeleteCount = cleaner1.getDeleteCount() + cleaner2.getDeleteCount();
            if (aggregateDeleteCount > expectedDeleteCount) {
                LOG.warn("expectedDeleteCount: {} ; aggregateDeleteCount: {}", expectedDeleteCount, aggregateDeleteCount);
            }
            return aggregateDeleteCount >= expectedDeleteCount;
        });
    }

Here is output from the most recent time I ran this test:

For totalFileCount=500:

expectedDeleteCount: 500 ; aggregateDeleteCount: 511

For totalFileCount=2000:

expectedDeleteCount: 2000 ; aggregateDeleteCount: 2053

[chrisrohr]

This test is in TimeBasedDirectoryCleanerConfigTest. Putting this here since I kept looking in TimeBasedDirectoryCleanerTest and couldn't find it. The error I consistently get is on line waitUntilReachExpectedDeleteCount(cleaner1, cleaner2, 300); and it timeout at 10 seconds and states that the file delete errors are ~150.

[chrisrohr]

Ok, I have a theory as to why this isn't working. When I introduce a small delay in between the two scheduleCleanup calls everything works correctly. I think that there must be something on the MacOS file system that is allowing our delete call to return true when 2 threads delete at the same time for both deletes. This causes our numbers to miscount. I know this test is ensuring that multiple cleaners can run at the same time, but I'm not sure that the use case of them starting at the exact same time is something we need to work around. I will submit a PR for this to at least have the tests pass and remove the @Enable

[sleberknight]

Yes, pretty sure the code works, given that we've used it in production for years now. So changing the code isn't necessary, which is what I think you are saying, only the test?

[chrisrohr]

Correct, this is only a test change.

[chrisrohr]

The small delay in setting up the 2 cleaners can be as low as 200ms for the test using 500 files and 400ms for the test using 2000 files. That is enough time for them both to delete but not step on each other.

[sleberknight]

And only add this delay on macOS? e.g. delayIfMacOs() and using "Mac OS X".equals(System.getProperty("os.name")) (or just using one of the many, many, many constants in SystemUtils in commons-lang3, e.g. SystemUtils.IS_OS_MAC