search

eXist-db / exist

eXist Native XML Database and Application Platform
https://exist-db.org
GNU Lesser General Public License v2.1
429 stars 179 forks source link

repeated retrieval of binary files with http:send-request() fails with TemporaryFileManager error #1863

Closed rvdb closed 6 years ago

rvdb commented 6 years ago

What is the problem

In eXist-4.1.0, repeated retrieval of binary files with the EXPath http:send-request() function fails with an error that seems to indicate a problem with management of temporary binary files on Windows:

An exception occurred during query execution: exerr:ERROR 
exerr:ERROR Unable to add binary value to result: 
C:\Users\me\AppData\Local\Temp\_mmtfm_f969fcfd-6ac0-4147-b0b8-a781296aad50938403981084997840\mmtf_15259068048824434207436387375223.tmp: 
The process cannot access the file because it is being used by another process.

This happens with all possible <binary-manager> settings in conf.xml, and seems to have been introduced since eXist-4.1.0; in eXist-4.0.0 (and tested down to eXist-3.6.0), this error does not occur.

What did you expect

I would expect repeated retrieval of binary files with the exPath http:send-request() function to succeed without errors.

Describe how to reproduce or add a test

On a standard eXist-4.1.0 installation (with all standard packages installed), run following XQuery twice:

declare namespace http="http://expath.org/ns/http-client";

http:send-request(<http:request href="http://localhost:8080/exist/apps/dashboard/resources/images/app.gif" method="get"/>)

While it succeeds the first time, subsequent calls throw the error mentioned above. The exist.log file contains this stacktrace:

2018-05-10 01:13:41,912 [qtp1812315561-40] INFO  (TemporaryFileManager.java [<init>]:82) - Temporary folder is: C:\Users\me\AppData\Local\Temp\_mmtfm_5c9489da-d9cc-4712-99dc-0b28359195963949822623512354281 
2018-05-10 01:13:41,955 [qtp1812315561-40] ERROR (TemporaryFileManager.java [returnTemporaryFile]:107) - Unable to delete temporary file: C:\Users\me\AppData\Local\Temp\_mmtfm_5c9489da-d9cc-4712-99dc-0b28359195963949822623512354281\mmtf_15259076219136792099700690257005.tmp 
java.nio.file.FileSystemException: C:\Users\me\AppData\Local\Temp\_mmtfm_5c9489da-d9cc-4712-99dc-0b28359195963949822623512354281\mmtf_15259076219136792099700690257005.tmp: The process cannot access the file because it is being used by another process.

  at sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:86) ~[?:1.8.0_172]
  at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:97) ~[?:1.8.0_172]
  at sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:102) ~[?:1.8.0_172]
  at sun.nio.fs.WindowsFileSystemProvider.implDelete(WindowsFileSystemProvider.java:269) ~[?:1.8.0_172]
  at sun.nio.fs.AbstractFileSystemProvider.deleteIfExists(AbstractFileSystemProvider.java:108) ~[?:1.8.0_172]
  at java.nio.file.Files.deleteIfExists(Files.java:1165) ~[?:1.8.0_172]
  at org.exist.util.io.TemporaryFileManager.returnTemporaryFile(TemporaryFileManager.java:105) ~[exist.jar:4.1.0]
  at org.expath.httpclient.model.exist.EXistResult.lambda$add$0(EXistResult.java:102) ~[exist-expath-20130805.jar:4.1.0]
  at org.exist.xquery.value.BinaryValueFromFile.lambda$close$0(BinaryValueFromFile.java:100) ~[exist.jar:4.1.0]
  at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_172]
  at org.exist.xquery.value.BinaryValueFromFile.close(BinaryValueFromFile.java:100) ~[exist.jar:4.1.0]
  at org.exist.xquery.XQueryContext$BinaryValueCleanupTask.cleanup(XQueryContext.java:3606) ~[exist.jar:4.1.0]
  at org.exist.xquery.XQueryContext.runCleanupTasks(XQueryContext.java:3729) ~[exist.jar:4.1.0]
  at org.exist.xquery.value.BinaryValueManager.runCleanupTasks(BinaryValueManager.java:14) ~[exist.jar:4.1.0]
  at org.exist.http.servlets.XQueryServlet.process(XQueryServlet.java:484) ~[exist-optional.jar:4.1.0]
  at org.exist.http.servlets.XQueryServlet.doPost(XQueryServlet.java:192) ~[exist-optional.jar:4.1.0]
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) ~[servlet-api-3.1.jar:3.1.0]
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[servlet-api-3.1.jar:3.1.0]
  at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:864) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:566) ~[jetty-security-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:163) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:73) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.exist.http.urlrewrite.Forward.doRewrite(Forward.java:51) ~[exist-optional.jar:4.1.0]
  at org.exist.http.urlrewrite.XQueryURLRewrite.doRewrite(XQueryURLRewrite.java:519) ~[exist-optional.jar:4.1.0]
  at org.exist.http.urlrewrite.XQueryURLRewrite.service(XQueryURLRewrite.java:338) ~[exist-optional.jar:4.1.0]
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[servlet-api-3.1.jar:3.1.0]
  at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:864) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1655) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at de.betterform.agent.web.filter.XFormsFilter.doFilter(XFormsFilter.java:171) ~[betterform-exist-5.1-SNAPSHOT-20160615.jar:?]
  at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1634) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524) ~[jetty-security-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) ~[jetty-servlet-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:219) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:666) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.Server.handle(Server.java:531) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) ~[jetty-server-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) ~[jetty-io-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) ~[jetty-io-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) ~[jetty-io-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:319) ~[jetty-util-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:175) ~[jetty-util-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:139) ~[jetty-util-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:754) [jetty-util-9.4.9.v20180320.jar:9.4.9.v20180320]
  at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:672) [jetty-util-9.4.9.v20180320.jar:9.4.9.v20180320]
  at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]

Further observations:

Context information

adamretter commented 6 years ago

eXist-db has a TemporaryFileManager, it is used in many places. We recently expanded its use to replace some other areas where a legacy temporary file manager was used.

The problem you are seeing is indicated because the temporary file that is used by eXist-db has subsequently been opened by some other process, and so eXist-db cannot delete it when it is finished with it. This is typically a Virus Scanner or Windows Search Service.

This is actually not really a problem, and you can safely ignore it for now. I think the logging is too severe here, rather than ERROR, it should be WARN level at the most. I will send a change to fix that.

dizzzz commented 6 years ago

What about ... creating a thread that cleans files that are older than say once an hour in the temp dit? The disk can actually flood ....

rvdb commented 6 years ago

Thanks for looking into this @adamretter. I've given it a try with https://github.com/eXist-db/exist/pull/1864, which does indeed reduce the amount of information in the logs, but does not fix the problem.

This is actually not really a problem, and you can safely ignore it for now. I think the logging is too severe here, rather than ERROR, it should be WARN level at the most. I will send a change to fix that.

Perhaps I hadn't stated clearly enough in my original report that the problem isn't just the logging, but the fact that retrieval of the binary files with http:send-request() actually fails with the same error message.

After your commit, behaviour remains the same: in eXide, a first call to http:send-request(<http:request href="http://localhost:8080/exist/apps/dashboard/resources/images/app.gif" method="get"/>) succeeds, but subsequent calls fail with the "exerr:ERROR Unable to add binary value to result" error.

2018-05-10 13_57_45-exide

In exist.log, logging now is reduced to:

2018-05-10 13:57:08,412 [qtp1980097967-53] WARN  (TemporaryFileManager.java [returnTemporaryFile]:108) - Unable to delete temporary file: C:\Users\RON~1.KAN\AppData\Local\Temp\_mmtfm_693a8863-3a27-4796-87c2-313e078f4ef52135163101174793632\mmtf_15259534218951031901657529973713.tmp due to: C:\Users\RON~1.KAN\AppData\Local\Temp\_mmtfm_693a8863-3a27-4796-87c2-313e078f4ef52135163101174793632\mmtf_15259534218951031901657529973713.tmp: The process cannot access the file because it is being used by another process.

I don't know if it is relevant, but if http:send-request() is called for the first time from the Java Admin client, a Java dialog pops up containing a slightly different error message:

org.xmldb.api.base.XMLDBException: Failed to invoke method retrieveFirstChunk in class org.exist.xmlrpc.RpcConnection: java.nio.file.FileSystemException: C:\Users\RON~1.KAN\AppData\Local\Temp\_mmtfm_693a8863-3a27-4796-87c2-313e078f4ef52135163101174793632\mmtf_15259531516226044908085437603660.tmp: The requested operation cannot be performed on a file with a user-mapped section open.

  at org.exist.xmldb.AbstractRemoteResource.getRemoteContentIntoLocalFile(AbstractRemoteResource.java:346)
  at org.exist.xmldb.AbstractRemoteResource.getExtendedContentInternal(AbstractRemoteResource.java:420)
  at org.exist.xmldb.RemoteXMLResource.getExtendedContent(RemoteXMLResource.java:224)
  at org.exist.xmldb.AbstractRemoteResource.getContent(AbstractRemoteResource.java:86)
  at org.exist.xmldb.RemoteXMLResource.getContent(RemoteXMLResource.java:137)
  at org.exist.client.QueryDialog$QueryThread.run(QueryDialog.java:593)
Caused by: org.apache.xmlrpc.XmlRpcException: Failed to invoke method retrieveFirstChunk in class org.exist.xmlrpc.RpcConnection: java.nio.file.FileSystemException: C:\Users\RON~1.KAN\AppData\Local\Temp\_mmtfm_693a8863-3a27-4796-87c2-313e078f4ef52135163101174793632\mmtf_15259531516226044908085437603660.tmp: The requested operation cannot be performed on a file with a user-mapped section open.

  at org.apache.xmlrpc.client.XmlRpcStreamTransport.readResponse(XmlRpcStreamTransport.java:197)
  at org.apache.xmlrpc.client.XmlRpcStreamTransport.sendRequest(XmlRpcStreamTransport.java:156)
  at org.apache.xmlrpc.client.XmlRpcHttpTransport.sendRequest(XmlRpcHttpTransport.java:143)
  at org.apache.xmlrpc.client.XmlRpcSunHttpTransport.sendRequest(XmlRpcSunHttpTransport.java:69)
  at org.apache.xmlrpc.client.XmlRpcClientWorker.execute(XmlRpcClientWorker.java:56)
  at org.apache.xmlrpc.client.XmlRpcClient.execute(XmlRpcClient.java:167)
  at org.apache.xmlrpc.client.XmlRpcClient.execute(XmlRpcClient.java:158)
  at org.apache.xmlrpc.client.XmlRpcClient.execute(XmlRpcClient.java:147)
  at org.exist.xmldb.AbstractRemoteResource.getRemoteContentIntoLocalFile(AbstractRemoteResource.java:268)
  ... 5 more
Caused by: org.apache.xmlrpc.XmlRpcException: Failed to invoke method retrieveFirstChunk in class org.exist.xmlrpc.RpcConnection: java.nio.file.FileSystemException: C:\Users\RON~1.KAN\AppData\Local\Temp\_mmtfm_693a8863-3a27-4796-87c2-313e078f4ef52135163101174793632\mmtf_15259531516226044908085437603660.tmp: The requested operation cannot be performed on a file with a user-mapped section open.

  at org.apache.xmlrpc.client.XmlRpcStreamTransport.readResponse(XmlRpcStreamTransport.java:197)
  at org.apache.xmlrpc.client.XmlRpcStreamTransport.sendRequest(XmlRpcStreamTransport.java:156)
  at org.apache.xmlrpc.client.XmlRpcHttpTransport.sendRequest(XmlRpcHttpTransport.java:143)
  at org.apache.xmlrpc.client.XmlRpcSunHttpTransport.sendRequest(XmlRpcSunHttpTransport.java:69)
  at org.apache.xmlrpc.client.XmlRpcClientWorker.execute(XmlRpcClientWorker.java:56)
  at org.apache.xmlrpc.client.XmlRpcClient.execute(XmlRpcClient.java:167)
  at org.apache.xmlrpc.client.XmlRpcClient.execute(XmlRpcClient.java:158)
  at org.apache.xmlrpc.client.XmlRpcClient.execute(XmlRpcClient.java:147)
  at org.exist.xmldb.AbstractRemoteResource.getRemoteContentIntoLocalFile(AbstractRemoteResource.java:268)
  at org.exist.xmldb.AbstractRemoteResource.getExtendedContentInternal(AbstractRemoteResource.java:420)
  at org.exist.xmldb.RemoteXMLResource.getExtendedContent(RemoteXMLResource.java:224)
  at org.exist.xmldb.AbstractRemoteResource.getContent(AbstractRemoteResource.java:86)
  at org.exist.xmldb.RemoteXMLResource.getContent(RemoteXMLResource.java:137)
  at org.exist.client.QueryDialog$QueryThread.run(QueryDialog.java:593)

When http:send-request() is called for a second time in the Java Admin Client, the same error is shown as in eXide :

An exception occurred during query execution: exerr:ERROR exerr:ERROR Unable to add binary value to result:C:\Users\RON~1.KAN\AppData\Local\Temp\_mmtfm_693a8863-3a27-4796-87c2-313e078f4ef52135163101174793632\mmtf_15259534218951031901657529973713.tmp: The process cannot access the file because it is being used by another process.
 [at line 5, column 1] [at line 5, column 1]
rvdb commented 6 years ago

@adamretter , @dizzzz : unfortunately, https://github.com/eXist-db/exist/pull/1864 does not fix the underlying issue reported above, so repeated calls on http:send-request() still fail miserably on Windows. Could someone please re-open this issue, since I can't?

adamretter commented 6 years ago

@rvdb Okay I can reproduce this.

After some initial investigation, I think the error message is misleading. The problem does not actually seem to be another process.

So the problem occurs in org.exist.xquery.value.BinaryValueFromFile the root cause of the problem is that two file handles are opened and only one is closed. However, this isn't quite the case, as we only explicitly open one file handle, the problem is Microsoft Windows is doing something strange with Memory Mapped Files.

I can in fact easily reproduce the problem (and others) outside eXist-db in some small standalone Java code (below). The issues occurs on the call to channel.map which seems to open a second handle to the file. I have yet to find any mechanism for unmapping the mapping (without reflection by calling java.nio.DirectByteBufferR.cleaner().clean()).

package com.company;

import java.io.IOException;
import java.io.OutputStream;
import java.io.RandomAccessFile;
import java.nio.MappedByteBuffer;
import java.nio.channels.FileChannel;
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.UUID;

public class Main {

    public static void main(final String[] args) throws IOException {
        // create a temp file with some junk in it
        final Path tmpFolder = Files.createTempDirectory("test-mapped" + UUID.randomUUID().toString());
        final Path file = Files.createTempFile(tmpFolder, "test-mapped" + System.currentTimeMillis(), ".tmp");
        writeJunk(file, 3431);

        // open the temp file and map a region of it for reading
        final RandomAccessFile raf = new RandomAccessFile(file.toFile(), "r");
        final FileChannel channel = raf.getChannel();
        final MappedByteBuffer buf = channel.map(FileChannel.MapMode.READ_ONLY, 0, channel.size());

        // close the temp file
        channel.close();
        raf.close();

        // Error 1: attempt to write over the temp file
        writeJunk(file, 123);                                           //java.nio.file.FileSystemException ... The requested operation cannot be performed on a file with a user-mapped section open.

        // Error 2: attempt to delete the temp file
        //Files.delete(file);                                               //java.nio.file.FileSystemException ... The process cannot access the file because it is being used by another process.

        // Error 3: attempt to copy over the temp file
        //final Path other = Files.createTempFile("other", ".tmp");
        //Files.copy(other, file, StandardCopyOption.REPLACE_EXISTING);     //java.nio.file.FileSystemException ... The process cannot access the file because it is being used by another process.
    }

    private static void writeJunk(final Path file, final int len) throws IOException {
        try (final OutputStream os = Files.newOutputStream(file)) {
            int val = 0;
            for (int i = 0; i < len; i++) {
                os.write(val++);

                if (val == 10) {
                    val = 0;
                }
            }
        }
    }
}
adamretter commented 6 years ago

It seems that there are known issues with Memory Mapped files on Microsoft Windows. I am absolutely incredulous that this can still be the case in 2018, but it seems that it is.

https://bugs.java.com/view_bug.do?bug_id=4715154 https://bugs.openjdk.java.net/browse/JDK-8028683 https://bugs.java.com/view_bug.do?bug_id=4724038

It looks like we can only use Memory Mapped IO on Microsoft Windows when the file will only be used once during the lifetime of an eXist-db instance and never reused in other ways (for example the B-Tree is fine, but mixing Memory Mapped IO ops on a file and standard IO ops is not).

This is quite the pain to say the least and will require much work!

One quicker solution, might be to differentiate between files that have been used with mapping operations and those that have not. Files that have been "mapped" cannot be reused with standard IO operations or FS operations, they can only be reused with mapping operations.

I will give this some thought...

duncdrum commented 6 years ago

wow thats one java 4 (!) issue still around. Reading through the comments it looks like a workaround is scheduled for java10. Did you see if that is live already?

adamretter commented 6 years ago

@rvdb Sorry for the delay, I just sent a PR.

rvdb commented 6 years ago

@adamretter Many thanks! I can confirm this resolves the issue (with all three InputStreamCache settings available in conf.xml, should that matter).

adamretter commented 6 years ago

@rvdb Excellent thanks :-)