JDK-8150344 : java/util/logging/FileHandlerLongLimit.java fails with FileNotFoundException
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.util.logging
  • Affected Version: 9
  • Priority: P4
  • Status: Open
  • Resolution: Unresolved
  • OS: windows
  • Submitted: 2016-02-22
  • Updated: 2018-09-11
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other
tbdUnresolved
Related Reports
Relates :  
Description
Failed to delete C:\\local\\aurora\\sandbox\\results\\workDir\\java\\util\\logging\\FileHandlerLongLimit\\FileHandler-afa99581-7811-421a-b75e-8b160eed165f.log: java.nio.file.AccessDeniedException: C:\\local\\aurora\\sandbox\\results\\workDir\\java\\util\\logging\\FileHandlerLongLimit\\FileHandler-afa99581-7811-421a-b75e-8b160eed165f.log
java.lang.RuntimeException: Unexpected exception received: java.io.FileNotFoundException: FileHandler-afa99581-7811-421a-b75e-8b160eed165f.log (Access is denied)
	at FileHandlerLongLimit.checkException(FileHandlerLongLimit.java:267)
	at FileHandlerLongLimit.test(FileHandlerLongLimit.java:437)
	at FileHandlerLongLimit$TestCase.run(FileHandlerLongLimit.java:74)
	at FileHandlerLongLimit.main(FileHandlerLongLimit.java:158)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:520)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:92)
	at java.lang.Thread.run(Thread.java:804)
Caused by: java.io.FileNotFoundException: FileHandler-afa99581-7811-421a-b75e-8b160eed165f.log (Access is denied)
	at java.io.FileOutputStream.open0(Native Method)
	at java.io.FileOutputStream.open(FileOutputStream.java:271)
	at java.io.FileOutputStream.<init>(FileOutputStream.java:215)
	at java.io.FileOutputStream.<init>(FileOutputStream.java:136)
	at java.util.logging.FileHandler.open(FileHandler.java:210)
	at java.util.logging.FileHandler.openFiles(FileHandler.java:578)
	at java.util.logging.FileHandler.<init>(FileHandler.java:440)
	at FileHandlerLongLimit.lambda$test$13(FileHandlerLongLimit.java:438)
	at FileHandlerLongLimit.testFileHandlerLimit(FileHandlerLongLimit.java:334)
	at FileHandlerLongLimit.lambda$test$14(FileHandlerLongLimit.java:437)
	at FileHandlerLongLimit.checkException(FileHandlerLongLimit.java:251)
	... 9 more
Comments
Yes - I saw that when analyzing the code today. This happens at this line: Files.deleteIfExists(Paths.get(PREFIX)); However, all handles on this file should have been released: it was created by a FileHandler that was closed in a finally block. Hopefully there's no anti-virus up & running when tests are run?
04-08-2016

Adding this line in jdk/test/java/util/logging/FileHandlerLongLimit.java public static FileHandler testFileHandlerLimit(FileHandlerSupplier supplier, long limit) throws Exception { Configure.doPrivileged(() -> { try { + System.out.println("Delete: " + Paths.get(PREFIX) + ", size = " + (new java.io.File(PREFIX)).length()); shows that the same file is created and deleted several times in the same run: Delete: FileHandler-cc049e7a-b46b-4b62-b5e5-f22a47ed5031.log, size = 103 Delete: FileHandler-cc049e7a-b46b-4b62-b5e5-f22a47ed5031.log, size = 345 Delete: FileHandler-cc049e7a-b46b-4b62-b5e5-f22a47ed5031.log, size = 103 Delete: FileHandler-cc049e7a-b46b-4b62-b5e5-f22a47ed5031.log, size = 345 Delete: FileHandler-cc049e7a-b46b-4b62-b5e5-f22a47ed5031.log, size = 103 Delete: FileHandler-cc049e7a-b46b-4b62-b5e5-f22a47ed5031.log, size = 345
04-08-2016

Thanks a lot Ioi. This is very helpful. Hopefully this is so transient that it won't happen again.
28-07-2016

https://msdn.microsoft.com/en-us/library/windows/desktop/aa363915(v=vs.85).aspx says: The DeleteFile function fails if an application attempts to delete a file that has other handles open for normal I/O or as a memory-mapped file (FILE_SHARE_DELETE must have been specified when other handles were opened). The DeleteFile function marks a file for deletion on close. Therefore, the file deletion does not occur until the last handle to the file is closed. Subsequent calls to CreateFile to open the file fail with ERROR_ACCESS_DENIED. So it's likely that (a) this process still has an open handle to the file, or (b) another process (possibly anti-virus?) still has an open handle to the file.
28-07-2016

one more rule FNFE RULE "java/util/logging/FileHandlerLongLimit.java" Exception java.io.FileNotFoundException: ...
22-06-2016

This only occurred once and only on Windows. Please assign to qe-test/hotspot if you think this is an infra issue.
22-02-2016

This is really strange. The file name is an UUID to prevent interference, and the file is in the scratch test dir that jtreg is supposed to clean afterwards. So interference with other tests is unlikely. It looks as if the test was able to create a file but was not able to delete it. Some win specific issue? Does this fail on other platforms as well? This is definitely an infrastructure or test issue - doesn't look like an issue in the logging code anyway. Maybe instrumenting the code of the test to check the file access rights after creation and before deletion could help.
22-02-2016

This could be an infra issue (Access is denied). Still assigning to core-libs for first investigation.
22-02-2016