jankotek
java.io.FileNotFoundException: doQueryStressDB_polling.db.wal.0 (Access is denied)
Hi,
One of my unit tests occasionally fails in mapdb. Not always. I tried in mapdb 3.0.1 and 3.0.5. This unit test performs a test of my application specific dB abstraction on top of mapdB. The dB is initialized with the following parameters:
this.db = DBMaker
.fileDB(f)
.closeOnJvmShutdown()
.transactionEnable()
.make();
Before I start the test, I delete the dB file and the .wal.0 file so that every test starts with a clean dB. I run this in Windows 10. The exception java.io.FileNotFoundException: doQueryStressDB_polling.db.wal.0 (Access is denied) indicates an access error, but the process has full control over the folder, manages to create the db and .wal.0 files and put's data in them. I also checked the disk space.
Stacktrace using mapdb 3.0.5:
org.mapdb.DBException$VolumeIOError
at org.mapdb.volume.RandomAccessFileVol.<init>(RandomAccessFileVol.java:63)
at org.mapdb.volume.RandomAccessFileVol$1.makeVolume(RandomAccessFileVol.java:26)
at org.mapdb.volume.VolumeFactory.makeVolume(VolumeFactory.java:20)
at org.mapdb.WriteAheadLog.startNextFile(WriteAheadLog.java:128)
at org.mapdb.WriteAheadLog.ensureFileReady(WriteAheadLog.java:1009)
at org.mapdb.WriteAheadLog.walPutRecord(WriteAheadLog.java:955)
at org.mapdb.StoreWAL.put(StoreWAL.kt:405)
at org.mapdb.HTreeMap.valueWrap(HTreeMap.kt:1210)
at org.mapdb.HTreeMap.putprotected(HTreeMap.kt:344)
at org.mapdb.HTreeMap.put(HTreeMap.kt:324)
at info.vancauwenberge.idm.driver.txtprotocol.shim.publisher.polling.PollStateFile.setPollInstance(PollStateFile.java:120)
at info.vancauwenberge.idm.driver.txtprotocol.shim.publisher.polling.PollStateFileTest.doQueryStressDB(PollStateFileTest.java:135)
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:497)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:86)
at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:675)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)
Caused by: java.io.FileNotFoundException: doQueryStressDB_polling.db.wal.0 (Access is denied)
at java.io.RandomAccessFile.open0(Native Method)
at java.io.RandomAccessFile.open(RandomAccessFile.java:316)
at java.io.RandomAccessFile.<init>(RandomAccessFile.java:243)
at org.mapdb.volume.RandomAccessFileVol.<init>(RandomAccessFileVol.java:51)
... 34 more
Stacktrace in 3.0.1 is equal except for one line:
at org.mapdb.HTreeMap.valueWrap(HTreeMap.kt:1210)
becomes:
at org.mapdb.HTreeMap.valueWrap(HTreeMap.kt:1208)
I noticed that this issue might be equal to this issue: https://github.com/jankotek/MapDB/issues/274 Issue 274 is also some kind of stress test, single threaded. In my scenario, I only change one element per commit and I only have one dB.
[edit] I noticed that this issue is equal to this issue as well: https://github.com/jankotek/mapdb/issues/788 I have the impression it is a Windows specific Exception.
[edit2] The only 'workaround' I found for now, is adding a try/catch. Upon exception I roll-back, close the dB and reopen the dB. Maybe closing and reopening is not needed...
Note: I tried switching to .fileChannelEnable(). This occasioanlly resulted in the following similar stack trace (mapdb 3.0.5):
org.mapdb.DBException$VolumeIOError
at org.mapdb.volume.FileChannelVol.<init>(FileChannelVol.java:96)
at org.mapdb.volume.FileChannelVol$1.makeVolume(FileChannelVol.java:35)
at org.mapdb.volume.VolumeFactory.makeVolume(VolumeFactory.java:20)
at org.mapdb.WriteAheadLog.startNextFile(WriteAheadLog.java:128)
at org.mapdb.WriteAheadLog.ensureFileReady(WriteAheadLog.java:1009)
at org.mapdb.WriteAheadLog.walPutRecord(WriteAheadLog.java:955)
at org.mapdb.StoreWAL.put(StoreWAL.kt:405)
at org.mapdb.HTreeMap.valueWrap(HTreeMap.kt:1210)
at org.mapdb.HTreeMap.putprotected(HTreeMap.kt:344)
at org.mapdb.HTreeMap.put(HTreeMap.kt:324)
at info.vancauwenberge.idm.driver.txtprotocol.shim.publisher.polling.PollStateFile.setPollInstance(PollStateFile.java:142)
at info.vancauwenberge.idm.driver.txtprotocol.shim.publisher.polling.PollStateFileTest.doQueryStressDB(PollStateFileTest.java:135)
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:497)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:86)
at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:675)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)
Caused by: java.nio.file.AccessDeniedException: doQueryStressDB_polling.db.wal.0
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.newFileChannel(WindowsFileSystemProvider.java:115)
at java.nio.channels.FileChannel.open(FileChannel.java:287)
at org.mapdb.volume.FileChannelVol.<init>(FileChannelVol.java:76)
... 34 more
Not really sure, maybe some file locking issue on windows. Would you give more detauls about OS, 64bit?....
JUnit OS: Windows 10, 64 bit. For the moment, all other related issues that mentioned an OS mentioned Windows. I also had the impression it was always under stressed scenarios. Till now, I did not yet encounter the exception in 'normal' (light weight) usage on a Linux 64 bit (Suse) system. Note: After implementing my workaround (=on exception, rollback, close and reopen dB) I now have a JUnit test of the stress test scenario, that loops 10 times over the stress test scenario. About half of the iterations need to 'recover' the exception, some even multiple times. Performance is naturally terrible when I do need to recover (times 5), but at least my data stored in the end. My guess would be that the OS does not clean up/release the wal.0 file fast enough (eg due to disk caching, some async cleanup by the OS,...) and that mapDB already request a new access to the exact same file. If that would be the case, implementing some round robbin of wal files (wal1->wal1->wal2->...) might be a workaround but recovering after a crash might be more problematic in this scenario.
Added a JUnit test scenario that reproduces the issue on a Windows 10 PC.
When running, the test fails most often after adding somewhere between 200 and 600 objects. I had some exception where I could add just over 1500 objects. MapdbIssue890.java.txt
Note: I just ran the above test on a Suse Linux VM without any problem. MapDB added 22635 objects to the map (mapdb 3.0.1) in 10 minutes. On version 3.0.5, 30599 objects were added in 10 minutes. For me, this proves it is indeed an OS specific issue: on Windows, deleting a file and recreating the same file does not always work, but works "most of the time".
For the moment, my work around is to try/catch this. Upon error, I close the dB, reopen it and try again.
I am also seeing this issue on windows 2008 64 bit. Single threaded app, below is the db setup. Trying to apply the workaround.
DB db = DBMaker.fileDB(Paths.get(dbDir, "we-employer-upload.database").toString()) .closeOnJvmShutdown() .transactionEnable() .make()
