Bug 63314 - java.nio.file.FileSystemException from unjar
Summary: java.nio.file.FileSystemException from unjar
Status: NEW
Alias: None
Product: Ant
Classification: Unclassified
Component: Core tasks (show other bugs)
Version: 1.10.5
Hardware: PC All
: P2 major with 1 vote (vote)
Target Milestone: ---
Assignee: Ant Notifications List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-04-03 18:18 UTC by David St. Denis
Modified: 2019-12-24 17:02 UTC (History)
1 user (show)



Attachments
test script (3.39 KB, text/xml)
2019-12-19 16:38 UTC, David St. Denis
Details

Note You need to log in before you can comment on or make changes to this bug.
Description David St. Denis 2019-04-03 18:18:28 UTC
This is a transient error that only intermittently occurs on Windows VMs, but does not seem to occur when Ant is running on a real Windows host. The files always appear to be extracted correctly. Sorry I cannot provide a working build file that demonstrates the error.
 S:\PLM559633_edf4\src\build\ant\soa\framework\TcSoaClient\libtcsoaclientmngd\targets.xml:36: Error while expanding S:\PLM559633_edf4\out\ivy\teamcenter\TcSoaStrongModel\20190320085010\TcSoaStrongModel_GenSrc.jar
    java.nio.file.FileSystemException: S:\PLM559633_edf4\out\meta\foundation\model\genCSharp\CPThemeBoardRevision.cs: The requested operation cannot be performed on a file with a user-mapped section open.
    
    at org.apache.tools.ant.taskdefs.Expand.expandFile(Expand.java:214)
    at org.apache.tools.ant.taskdefs.Expand.execute(Expand.java:157)
    at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:292)
    at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:99)
    at org.apache.tools.ant.Task.perform(Task.java:350)
    at org.apache.tools.ant.Target.execute(Target.java:449)
    at org.apache.tools.ant.Target.performTasks(Target.java:470)
    at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1388)
    at org.apache.tools.ant.Project.executeTarget(Project.java:1361)
    at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(DefaultExecutor.java:41)
    at org.apache.tools.ant.Project.executeTargets(Project.java:1251)
    at org.apache.tools.ant.Main.runBuild(Main.java:834)
    at org.apache.tools.ant.Main.startAnt(Main.java:223)
    at org.apache.tools.ant.launch.Launcher.run(Launcher.java:284)
    at org.apache.tools.ant.launch.Launcher.main(Launcher.java:101)
    Caused by: java.nio.file.FileSystemException: S:\PLM559633_edf4\out\meta\foundation\model\genCSharp\CPThemeBoardRevision.cs: The requested operation cannot be performed on a file with a user-mapped section open.
    
    at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86)
    at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
    at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102)
    at sun.nio.fs.WindowsFileSystemProvider.newByteChannel(WindowsFileSystemProvider.java:230)
    at java.nio.file.spi.FileSystemProvider.newOutputStream(FileSystemProvider.java:434)
    at java.nio.file.Files.newOutputStream(Files.java:216)
    at org.apache.tools.ant.taskdefs.Expand.extractFile(Expand.java:361)
    at org.apache.tools.ant.taskdefs.Expand.expandFile(Expand.java:199)
    ... 17 more
Comment 1 Eugène Adell 2019-04-03 21:09:09 UTC
From what I found in google & SO, this exception says the file is already opened when you're accessing it, or there is not enough time between closing it and reopening it.

It might be because an antivirus is scanning it (did you exclude your VM files from the antivirus ?)

One Oracle's page suggests to use JDK 1.6 if you are using a newer version.
Comment 2 Jaikiran Pai 2019-04-04 02:40:55 UTC
David, can you add the output of 

java -version

being used in this build to show us which vendor and version of Java is being used?
Comment 3 David St. Denis 2019-04-04 12:52:01 UTC
java version "1.8.0_102"
Java(TM) SE Runtime Environment (build 1.8.0_102-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, mixed mode)
Comment 4 Eugène Adell 2019-06-08 19:38:22 UTC
You didn't say what software you are using for virtualization (kvm, VMware ESX,..) and this would be interesting for people who have the knowledge and hopefully could answer.
Please share your config (cpu/memory) and your jvm settings.

Here is what I found for ESX, and I recommend reading carefully : https://communities.vmware.com/api/core/v3/attachments/17786/data

In short.. 
It's obvious, but did you install the VM tools ?
Is the VM dedicated to one task (your Java program) or is doing many things ? It maybe should do only one thing.
Are CPU/memory configured wisely ore are you overconsuming resources ? Try configuring them smaller (less CPU, less memory).
Is NTP configured correctly ? Try -XX:+ForceTimeHighResolution 

Please keep us updated if you try anything above.
Comment 5 David St. Denis 2019-12-19 16:38:55 UTC
Created attachment 36924 [details]
test script


Running this script on a real (non virtual) Windows machine works fine. I've never had an error yet. At least in the several dozen times I've run it never experienced an error.

However tunning this script on a Windows virtual machine I get the following 2 types of errors and warnings intermittently. More often the AccessDenied trace than the FileSystemException.

E:\udu\t100.xml:79: Failed to copy E:\udu\SSS\fA670 to E:\udu\DDD\fA670 due to java.nio.file.AccessDeniedException E:\udu\DDD\fA670
        at org.apache.tools.ant.taskdefs.Copy.doFileOperations(Copy.java:899)
        at org.apache.tools.ant.taskdefs.Copy.execute(Copy.java:567)
        at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:292)
        at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:99)
        at org.apache.tools.ant.Task.perform(Task.java:350)
        at java.util.Vector.forEach(Vector.java:1249)
        at org.apache.tools.ant.taskdefs.Sequential.execute(Sequential.java:67)
        at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:292)
        at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:99)
        at org.apache.tools.ant.Task.perform(Task.java:350)
        at org.apache.tools.ant.taskdefs.MacroInstance.execute(MacroInstance.java:391)
        at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:292)
        at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:99)
        at org.apache.tools.ant.Task.perform(Task.java:350)
        at org.apache.tools.ant.taskdefs.Parallel$TaskRunnable.run(Parallel.java:454)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.nio.file.AccessDeniedException: E:\udu\DDD\fA670
        at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:83)
        at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97)
        at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102)
        at sun.nio.fs.WindowsFileSystemProvider.newByteChannel(WindowsFileSystemProvider.java:230)
        at java.nio.file.spi.FileSystemProvider.newOutputStream(FileSystemProvider.java:434)
        at java.nio.file.Files.newOutputStream(Files.java:216)
        at org.apache.tools.ant.util.FileUtils.newOutputStream(FileUtils.java:1769)
        at org.apache.tools.ant.types.resources.FileResource.getOutputStream(FileResource.java:267)
        at org.apache.tools.ant.types.resources.FileResource.getOutputStream(FileResource.java:241)
        at org.apache.tools.ant.util.ResourceUtils.getOutputStream(ResourceUtils.java:791)
        at org.apache.tools.ant.util.ResourceUtils.copyUsingStreams(ResourceUtils.java:765)
        at org.apache.tools.ant.util.ResourceUtils.copyResource(ResourceUtils.java:435)
        at org.apache.tools.ant.util.FileUtils.copyFile(FileUtils.java:565)
        at org.apache.tools.ant.taskdefs.Copy.doFileOperations(Copy.java:882)
        ... 24 more

OR

E:\udu\t100.xml:79: Failed to copy E:\udu\SSS\fA298 to E:\udu\DDD\fA298 due to java.nio.file.FileSystemException E:\udu\DDD\fA298: The requested operation cannot be performed on a file with a user-mapped section open.

        at org.apache.tools.ant.taskdefs.Parallel.spinThreads(Parallel.java:395)
        at org.apache.tools.ant.taskdefs.Parallel.execute(Parallel.java:209)
        at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:292)
        at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:99)
        at org.apache.tools.ant.Task.perform(Task.java:350)
        at org.apache.tools.ant.Target.execute(Target.java:449)
        at org.apache.tools.ant.Target.performTasks(Target.java:470)
        at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1388)
        at org.apache.tools.ant.Project.executeTarget(Project.java:1361)
        at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(DefaultExecutor.java:41)
        at org.apache.tools.ant.Project.executeTargets(Project.java:1251)
        at org.apache.tools.ant.Main.runBuild(Main.java:834)
        at org.apache.tools.ant.Main.startAnt(Main.java:223)
        at org.apache.tools.ant.launch.Launcher.run(Launcher.java:284)
        at org.apache.tools.ant.launch.Launcher.main(Launcher.java:101)

AND always receive warnings of this type when the script is run:
Attempt to copy E:\udu\SSS\fA714 to E:\udu\DDD\fA714 using NIO Channels failed due to 'E:\udu\DDD\fA714: The requested operation cannot be performed on a file with a user-mapped section open.
Attempt to copy E:\udu\SSS\fA825 to E:\udu\DDD\fA825 using NIO Channels failed due to 'E:\udu\DDD\fA825: The requested operation cannot be performed on a file with a user-mapped section open.
Attempt to copy E:\udu\SSS\fA888 to E:\udu\DDD\fA888 using NIO Channels failed due to 'E:\udu\DDD\fA888: The requested operation cannot be performed on a file with a user-mapped section open.


My guess is this has more to do with the JVM interaction with the VM than Ant. And I'm aware that my problem here is that I'm copying to the same destination using multiple threads. In the real world this is separate Ant builds copying to the same destination independently, so it's not as easy to simply just not do as in this trivial concoction.
Comment 6 Eugène Adell 2019-12-19 22:47:33 UTC
I ran your script several times without any problem on WIN SERVER 2016 hosted on VMWARE WORKSTATION 15 Pro

>bin\ant -v -f 63314.xml
Apache Ant(TM) version 1.10.7 compiled on September 1 2019
Buildfile: C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\63314.xml
Detected Java version: 1.8 in: C:\Program Files\Java\jre1.8.0_231
Detected OS: Windows Server 2016
parsing buildfile C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\63314.xml with URI = file:/C:/Users/Administrateur/Downloads/apache-ant-1.10.7-bin/apache-ant-1.10.7/63314.xml
Project base dir set to: C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7
parsing buildfile jar:file:/C:/Users/Administrateur/Downloads/apache-ant-1.10.7-bin/apache-ant-1.10.7/lib/ant.jar!/org/apache/tools/ant/antlib.xml with URI = jar:file:/C:/Users/Administrateur/Downloads/apache-ant-1.10.7-bin/apache-ant-1.10.7/lib/ant.jar!/org/apache/tools/ant/antlib.xml from a zip file
    [mkdir] Created dir: C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\SSS
    [mkdir] Created dir: C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
 [macrodef] creating macro  f1
 [macrodef] creating macro  f10
 [macrodef] creating macro  f100
 [macrodef] creating macro  f1000
 [macrodef] creating macro  copy1
 [macrodef] creating macro  copy2

BUILD SUCCESSFUL
Total time: 4 seconds


May I ask which versions you are running ?
Comment 7 David St. Denis 2019-12-20 14:48:34 UTC
java version "1.8.0_102"
Java(TM) SE Runtime Environment (build 1.8.0_102-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, mixed mode)

Apache Ant(TM) version 1.10.5 compiled on July 10 2018

Windows Server 2016 virtual machine

You should run target "t1" or "t2" in my sample script to actually do the copying.
Comment 8 Eugène Adell 2019-12-20 18:23:04 UTC
I downgraded to 8u102 and still no problem with t1 or t2 targets. But sometimes there are less than 1000 files copied, is this normal ? 

     [copy] Copying 992 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD



>bin\ant  -f 63314.xml  t1
Unable to locate tools.jar. Expected to find it in C:\Program Files\Java\jre1.8.0_102\lib\tools.jar
Buildfile: C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\63314.xml
   [delete] Deleting directory C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\SSS
    [mkdir] Created dir: C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\SSS
   [delete] Deleting directory C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
    [mkdir] Created dir: C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD

t1:
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD
     [copy] Copying 1000 files to C:\Users\Administrateur\Downloads\apache-ant-1.10.7-bin\apache-ant-1.10.7\DDD

BUILD SUCCESSFUL
Total time: 9 seconds
Comment 9 Eugène Adell 2019-12-20 22:45:04 UTC
can you check if the clock rate is the default one (15,625ms) ? You can run ClockRes for that ( https://docs.microsoft.com/fr-fr/sysinternals/downloads/clockres )
Comment 10 David St. Denis 2019-12-23 14:23:57 UTC
(In reply to Eugène Adell from comment #9)
> can you check if the clock rate is the default one (15,625ms) ? You can run
> ClockRes for that (
> https://docs.microsoft.com/fr-fr/sysinternals/downloads/clockres )


From Windows Virtual Machine:
Maximum timer interval: 15.625 ms
Minimum timer interval: 0.500 ms
Current timer interval: 15.625 ms

From Real machine:
Maximum timer interval: 15.625 ms
Minimum timer interval: 0.500 ms
Current timer interval: 1.001 ms
Comment 11 Eugène Adell 2019-12-24 14:20:40 UTC
Are you using write caching at the physical disk level or at the VM's virtual disk (if both it's redundant and bad) ? Maybe try changing these settings.
Comment 12 Eugène Adell 2019-12-24 16:49:00 UTC
Just found this interesting parameter *performGCOnFailedDelete* on the move task that could describe a similar behavior :

https://ant.apache.org/manual/Tasks/move.html


Are you using NFS ?

Also found this link which also talks about Garbage Collection :

https://kb.vmware.com/s/article/1033871

I don't have more technical details, maybe anyone has the answer of this wrong behavior here ? With the project file you gave, could you try MOVE instead of COPY ?
Comment 13 Eugène Adell 2019-12-24 17:02:59 UTC
Maybe the cause ?

JDK-4715154 : (fs) Cannot delete file if memory mapped with FileChannel.map (windows)
Resolution : WON'T FIX

https://bugs.java.com/bugdatabase/view_bug.do?bug_id=4715154