ADDITIONAL SYSTEM INFORMATION :
OS: Mac OS Monterey 12.5.1 / Mac OS Ventura 13.6.6
IMPLEMENTOR="Eclipse Adoptium"
IMPLEMENTOR_VERSION="Temurin-17.0.9+9"
IMPLEMENTOR_VERSION="Temurin-17.0.11+9"


A DESCRIPTION OF THE PROBLEM :
The ENTRY_CREATE event (java.nio.file.WatchService) is not always emitted when creating subfolder in the watched directory, renaming it and copying file there.

This behaviour was observed in the project which is using Spring Integration library
and initially the bug has been reported for that Spring library.

However, it turned out this is related to the JDK, not to that library.

This is only reproducible on Mac (reproduced for Temurin-17.0.9+9 and Temurin-17.0.11+9).
I've tried to reproduce it also on MAC using the different version of JDK:
IMPLEMENTOR="Oracle Corporation"
JAVA_VERSION="17.0.4.1"
JAVA_VERSION_DATE="2022-08-18"
but it is working fine.... !!!

REGRESSION : Last worked in version 17.0.11

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :

1. Configure FileReadingMessageSource in the following way:
FileReadingMessageSource messageSource = new FileReadingMessageSource();
messageSource.setDirectory(new File(inputDirectory));
messageSource.setUseWatchService(true);
messageSource.setWatchEvents(CREATE, MODIFY, DELETE);

2. Configure a simple flow that simply deletes the file

3. Prepare a file with minimum size of 17 KB (test.zip)

4. Configure logger for org.srpingframework.integration.file package (DEBUG level)

5. Execute the following command in the shell inside the watched directory:
mkdir b1; sleep 2; mv b1 b2; sleep 3; cp /Users/<USERNAME>/sandbox/test/test.zip b2/; sleep 2; mkdir b3; sleep 2; mv b3 b4; sleep 3; cp /Users/<USERNAME>/sandbox/test/test.zip b4/; sleep 2; mkdir b5; sleep 2; mv b5 b6; sleep 3; cp /Users/<USERNAME>/sandbox/test/test.zip b6/; sleep 2; mkdir b7; sleep 2; mv b7 b8; sleep 3; cp /Users/<USERNAME>/sandbox/test/test.zip b8/; sleep 2;

6. The ENTRY_CREATE is not emitted for all files (in the example below, it is only emitted for b4 folder and missing for b2, b6 and b8):
2024-05-17 10:44:08.150 [main] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input for file events 2024-05-17 10:44:11.178 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users<USERNAME>/sandbox/input/b1] 2024-05-17 10:44:11.179 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b1 for file events 2024-05-17 10:44:13.167 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b2] 2024-05-17 10:44:13.168 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b2 for file events 2024-05-17 10:44:13.169 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_DELETE] for file [/Users/<USERNAME>/sandbox/input/b1] 2024-05-17 10:44:17.171 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b2] 2024-05-17 10:44:19.167 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b3] 2024-05-17 10:44:19.167 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b3 for file events 2024-05-17 10:44:21.164 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b4] 2024-05-17 10:44:21.164 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b4 for file events 2024-05-17 10:44:21.165 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_DELETE] for file [/Users/<USERNAME>/sandbox/input/b3] 2024-05-17 10:44:23.170 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b4] 2024-05-17 10:44:24.170 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b4/test.zip] 2024-05-17 10:44:24.171 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Added to queue: [/Users/<USERNAME>/sandbox/input/b4/test.zip] 2024-05-17 10:44:24.177 [Thread_5] INFO o.s.i.handler.LoggingHandler - GenericMessage [payload=/Users/<USERNAME>/sandbox/input/b4/test.zip, headers={sourceCountry=global, feedName=reuters, file_name=test.zip, targetPath=data, file_originalFile=/Users/<USERNAME>/sandbox/input/b4/test.zip, source=Global_Relay, priority=5, file_relativePath=b4/test.zip, uncompress=true, sieve=true, id=ed14f9ab-335f-b547-58db-0aa4b735dac5, decrypt=false, sourcePath=/Users/<USERNAME>/sandbox/input, remoteFeedName=reuters, timestamp=1715935464177}] 2024-05-17 10:44:25.172 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b5] 2024-05-17 10:44:25.172 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b5 for file events 2024-05-17 10:44:25.172 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b4] 2024-05-17 10:44:26.172 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_DELETE] for file [/Users/<USERNAME>/sandbox/input/b4/test.zip] 2024-05-17 10:44:27.168 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b6] 2024-05-17 10:44:27.168 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b6 for file events 2024-05-17 10:44:27.169 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_DELETE] for file [/Users/<USERNAME>/sandbox/input/b5] 2024-05-17 10:44:31.166 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b6] 2024-05-17 10:44:33.166 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b7] 2024-05-17 10:44:33.166 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b7 for file events 2024-05-17 10:44:35.169 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b8] 2024-05-17 10:44:35.169 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - registering: /Users/<USERNAME>/sandbox/input/b8 for file events 2024-05-17 10:44:35.169 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_DELETE] for file [/Users/<USERNAME>/sandbox/input/b7] 2024-05-17 10:44:39.168 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b8]

7. It seems the subfolders b2, b6 and b8 are not registered properly as when executing the following command (copying different file to these subfolders):
cp /Users/<USERNAME>/sandbox/test/test2.zip b2/ cp /Users/<USERNAME>/sandbox/test/test2.zip b4/ cp /Users/<USERNAME>/sandbox/test/test2.zip b6/ cp /Users/<USERNAME>/sandbox/test/test2.zip b8/

8. The ENTRY_CREATE and ENTRY_DELETE are only emitted for the b4 subfolder:
2024-05-17 11:22:51.107 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b2] 2024-05-17 11:23:06.107 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_CREATE] for file [/Users/<USERNAME>/sandbox/input/b4/test2.zip] 2024-05-17 11:23:06.108 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Added to queue: [/Users/<USERNAME>/sandbox/input/b4/test2.zip] 2024-05-17 11:23:06.111 [Thread_25] INFO o.s.i.handler.LoggingHandler - GenericMessage [payload=/Users/<USERNAME>/sandbox/input/b4/test2.zip, headers={sourceCountry=global, feedName=reuters, file_name=test2.zip, targetPath=data, file_originalFile=/Users/<USERNAME>/sandbox/input/b4/test2.zip, source=Global_Relay, priority=5, file_relativePath=b4/test2.zip, uncompress=true, sieve=true, id=5ecc527e-1188-a57e-6afd-571d2ba75431, decrypt=false, sourcePath=/Users/<USERNAME>/sandbox/input, remoteFeedName=reuters, timestamp=1715937786111}] 2024-05-17 11:23:07.108 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b4] 2024-05-17 11:23:08.104 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_DELETE] for file [/Users/<USERNAME>/sandbox/input/b4/test2.zip] 2024-05-17 11:23:13.106 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b6] 2024-05-17 11:23:21.109 [scheduling-1] DEBUG o.s.i.file.FileReadingMessageSource - Watch event [ENTRY_MODIFY] for file [/Users/<USERNAME>/sandbox/input/b8]

9. Everything works fine if the sleep is removed from command above (point 5) !!!



EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Expected behaviour:
The ENTRY_CREATE should be always emitted when renaming the subfolder of the watched directory and copying file there.
ACTUAL -
The ENTRY_CREATE event is not always emitted which is making WatchService not reliable mechanism in OpenJDK (it seems it is working fine against Oracle JDK)

---------- BEGIN SOURCE ----------

The bug can be reproduced by launching Spring Boot application and executing commands in the shell.
I haven't tried to make the same operations in the Java Test as the WathService mechanism is supposed to collaborate with file system notifications.
---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
Do not use sleep commands between renaming the folder and copying the file or use Oracle JDK which seems to work just fine....
I haven't managed to reproduce this issue on Windows but I suspect it may occur for Linux as well....

FREQUENCY : often