Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

IndexOutOfBounds when storing with channel count >= 2 (more likely with higher channel count) #150

Closed
m-stoer opened this issue Aug 13, 2020 · 11 comments
Assignees

Comments

@m-stoer
Copy link
Contributor

m-stoer commented Aug 13, 2020

Tested on current master (80fc56f)

Whenever I start the storage with backup enabled and a channel count of 2, the first start has no problems. But when I start the application again, it will give me an IndexOutOfBounds when trying to copy a channel file to the backup location. This doesn't happen when the channel count is 1.

If the channel count is greater or equal to 4 then I always get this exception on the first store.

This is my code:

final List<String> root = new ArrayList<>();
final NioFileSystem fs = NioFileSystem.New();

System.out.println("Creating and starting...");
final EmbeddedStorageManager x = EmbeddedStorage.Foundation()
	.setConfiguration(
		StorageConfiguration.Builder()
			.setChannelCountProvider(StorageChannelCountProvider.New(4))
			.setBackupSetup(
				StorageBackupSetup.New(
					StorageBackupFileProvider.Builder(fs)
						.setDirectory(fs.ensureDirectoryPath("backup"))
						.createFileProvider()
				)
			)
			.createConfiguration()
	)
	.setRoot(root)
	.createEmbeddedStorageManager()
	.start();

root.add("HEHE");

System.out.println("Storing...");
x.storeRoot();

Thread.sleep(1000);
System.out.println("Shutting down...");
x.shutdown();

(The sleep is there so the exception output doesn't overlap with the exception message that comes from the shutdown)

Exception when starting with channel count of 4:

Exception in thread "MicroStream-StorageChannel-3" Exception in thread "MicroStream-StorageChannel-0" Exception in thread "MicroStream-StorageChannel-1" Exception in thread "MicroStream-StorageChannel-2" one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_3/channel_3_1.dat@220+0 -> Pommes/channel_3/channel_3_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:308)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:385)
	at java.base/java.lang.Thread.run(Thread.java:834)
one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_3/channel_3_1.dat@220+0 -> Pommes/channel_3/channel_3_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:308)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:385)
	at java.base/java.lang.Thread.run(Thread.java:834)
one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_3/channel_3_1.dat@220+0 -> Pommes/channel_3/channel_3_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:308)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:385)
	at java.base/java.lang.Thread.run(Thread.java:834)
one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_3/channel_3_1.dat@220+0 -> Pommes/channel_3/channel_3_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:308)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:385)
	at java.base/java.lang.Thread.run(Thread.java:834)
Exception in thread "MicroStream-StorageBackupHandler" one.microstream.storage.exceptions.StorageExceptionBackupCopying: storage/channel_3/channel_3_1.dat@220+0 -> Pommes/channel_3/channel_3_1.dat
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:471)
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:485)
	at one.microstream.storage.types.StorageBackupItemQueue$Default$Item.processBy(StorageBackupItemQueue.java:178)
	at one.microstream.storage.types.StorageBackupItemQueue$Default.processNextItem(StorageBackupItemQueue.java:109)
	at one.microstream.storage.types.StorageBackupHandler$Default.run(StorageBackupHandler.java:212)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: one.microstream.storage.exceptions.StorageExceptionBackupCopying: storage/channel_3/channel_3_1.dat@220+0 -> Pommes/channel_3/channel_3_1.dat
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:462)
	... 5 more
Caused by: one.microstream.storage.exceptions.StorageExceptionIoReading
	at one.microstream.storage.types.StorageFileEntityDataIterator$Default.fillBuffer(StorageFileEntityDataIterator.java:174)
	at one.microstream.storage.types.StorageFileEntityDataIterator$Internal.iterateEntityData(StorageFileEntityDataIterator.java:45)
	at one.microstream.storage.types.StorageDataFileValidator$Default.validateFile(StorageDataFileValidator.java:112)
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:457)
	... 5 more
Caused by: one.microstream.storage.exceptions.StorageExceptionIoReading
	at one.microstream.storage.types.StorageFile$Abstract.readBytes(StorageFile.java:149)
	at one.microstream.storage.types.StorageFileEntityDataIterator$Default.fillBuffer(StorageFileEntityDataIterator.java:170)
	... 8 more
Caused by: one.microstream.exceptions.IndexBoundsException: Index out of bounds: 220 not in [0;220[ (StartIndex >= bound)
	at one.microstream.io.XIO.internalRead(XIO.java:1176)
	at one.microstream.io.XIO.read(XIO.java:1162)
	at one.microstream.afs.nio.NioIoHandler$Default.specificReadBytes(NioIoHandler.java:372)
	at one.microstream.afs.nio.NioIoHandler$Default.specificReadBytes(NioIoHandler.java:1)
	at one.microstream.afs.AIoHandler$Abstract.readBytes(AIoHandler.java:752)
	at one.microstream.afs.AReadableFile.readBytes(AReadableFile.java:84)
	at one.microstream.storage.types.StorageFile$Abstract.readBytes(StorageFile.java:145)
	... 9 more
@m-stoer m-stoer changed the title IndexOutOfBounds when storing with storage with channel count >= 2 & backup enabled IndexOutOfBounds when storing with channel count >= 2 & backup enabled Aug 13, 2020
@hg-ms
Copy link
Contributor

hg-ms commented Aug 14, 2020

I got a similar exception at startup, channels are set to 4 and backup is enabled.
In my case the exception was thrown during the fourth startup. A second test required much more starts to get the same exception.

Exception in thread "main" one.microstream.storage.exceptions.StorageException: Problem in channel 0
	at one.microstream.storage.types.StorageChannelTask$Abstract.checkForProblems(StorageChannelTask.java:65)
	at one.microstream.storage.types.StorageChannelTask$Abstract.waitOnCompletion(StorageChannelTask.java:124)
	at one.microstream.storage.types.StorageSystem$Default.startThreads(StorageSystem.java:295)
	at one.microstream.storage.types.StorageSystem$Default.internalStartUp(StorageSystem.java:473)
	at one.microstream.storage.types.StorageSystem$Default.start(StorageSystem.java:550)
	at one.microstream.storage.types.StorageSystem$Default.start(StorageSystem.java:1)
	at one.microstream.storage.types.StorageSystemLogging$Default.start(StorageSystemLogging.java:92)
	at one.microstream.storage.types.EmbeddedStorageManager$Default.start(EmbeddedStorageManager.java:208)
	at one.microstream.storage.types.EmbeddedStorageManager$Default.start(EmbeddedStorageManager.java:1)
	at one.microstream.storage.types.EmbeddedStorageManagerLogging$Default.start(EmbeddedStorageManagerLogging.java:43)
	at one.microstream.storage.types.EmbeddedStorageFoundation.start(EmbeddedStorageFoundation.java:199)
	at one.microstream.storage.types.EmbeddedStorageFoundation.start(EmbeddedStorageFoundation.java:167)
	at one.microstream.storage.logging.MainTestStorageLogging.main(MainTestStorageLogging.java:69)
Caused by: one.microstream.storage.exceptions.StorageExceptionIoReading
	at one.microstream.storage.types.StorageEntityInitializer$Default.fillBuffer(StorageEntityInitializer.java:267)
	at one.microstream.storage.types.StorageEntityInitializer$Default.indexEntities(StorageEntityInitializer.java:168)
	at one.microstream.storage.types.StorageEntityInitializer$Default.registerFileEntities(StorageEntityInitializer.java:111)
	at one.microstream.storage.types.StorageEntityInitializer$Default.registerEntities(StorageEntityInitializer.java:89)
	at one.microstream.storage.types.StorageEntityInitializer$Default.registerEntities(StorageEntityInitializer.java:71)
	at one.microstream.storage.types.StorageEntityInitializer$Default.registerEntities(StorageEntityInitializer.java:1)
	at one.microstream.storage.types.StorageFileManager$Default.initializeForExistingFiles(StorageFileManager.java:987)
	at one.microstream.storage.types.StorageFileManager$Default.initializeStorage(StorageFileManager.java:878)
	at one.microstream.storage.types.StorageChannel$Default.initializeStorage(StorageChannel.java:721)
	at one.microstream.storage.types.StorageChannelTaskInitialize$Default.succeed(StorageChannelTaskInitialize.java:186)
	at one.microstream.storage.types.StorageChannelTaskInitialize$Default.succeed(StorageChannelTaskInitialize.java:1)
	at one.microstream.storage.types.StorageChannelSynchronizingTask$AbstractCompletingTask.synchronizedComplete(StorageChannelSynchronizingTask.java:61)
	at one.microstream.storage.types.StorageChannelSynchronizingTask$AbstractCompletingTask.complete(StorageChannelSynchronizingTask.java:109)
	at one.microstream.storage.types.StorageChannelTask$Abstract.processBy(StorageChannelTask.java:217)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:388)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:475)
	at one.microstream.storage.types.StorageChannelLogging$Default.run(StorageChannelLogging.java:104)
	at java.lang.Thread.run(Thread.java:748)
Caused by: one.microstream.storage.exceptions.StorageExceptionIoReading
	at one.microstream.storage.types.StorageFile$Abstract.readBytes(StorageFile.java:162)
	at one.microstream.storage.types.StorageEntityInitializer$Default.fillBuffer(StorageEntityInitializer.java:263)
	... 17 more
Caused by: one.microstream.exceptions.IndexBoundsException: Index out of bounds: 0 not in [0;0[ (StartIndex >= bound)
	at one.microstream.io.XIO.internalRead(XIO.java:1176)
	at one.microstream.io.XIO.read(XIO.java:1152)
	at one.microstream.afs.nio.NioIoHandler$Default.specificReadBytes(NioIoHandler.java:390)
	at one.microstream.afs.nio.NioIoHandler$Default.specificReadBytes(NioIoHandler.java:1)
	at one.microstream.afs.AIoHandler$Abstract.readBytes(AIoHandler.java:765)
	at one.microstream.afs.AReadableFile.readBytes(AReadableFile.java:90)
	at one.microstream.storage.types.StorageFile$Abstract.readBytes(StorageFile.java:158)
	... 18 more

@hg-ms
Copy link
Contributor

hg-ms commented Aug 14, 2020

Just got the same exception as i just posted with 2 channels and no Backup...

@m-stoer
Copy link
Contributor Author

m-stoer commented Aug 14, 2020

I have set my channel count to 16 and disabled the setup backup and now I also get the same exception on the second start. So it seems that it has to do with the channel count and not with the backup.

@m-stoer m-stoer changed the title IndexOutOfBounds when storing with channel count >= 2 & backup enabled IndexOutOfBounds when storing with channel count >= 2 (more likely with higher channel count) Aug 14, 2020
@zdenek-jonas
Copy link
Contributor

image
I can also see it in test. It happens very sporadically.

@tm-ms
Copy link
Contributor

tm-ms commented Aug 31, 2020

With my initial attempts, I could not reproduce this.
Will keep trying :-).

@tm-ms tm-ms self-assigned this Aug 31, 2020
@fh-ms
Copy link
Contributor

fh-ms commented Sep 23, 2020

100% reproducible on my side:

final List<String> root = new ArrayList<>();
final NioFileSystem fs = NioFileSystem.New();

final EmbeddedStorageManager storageManager = EmbeddedStorage.Foundation()
	.setConfiguration(
		StorageConfiguration.Builder()
			.setChannelCountProvider(StorageChannelCountProvider.New(4))
			.setBackupSetup(
				StorageBackupSetup.New(
					StorageBackupFileProvider.Builder(fs)
						.setDirectory(fs.ensureDirectoryPath("backup"))
						.createFileProvider()
				)
			)
			.createConfiguration()
	)
	.setRoot(root)
	.createEmbeddedStorageManager()
	.start();

root.add("HEHE");

storageManager.storeRoot();

storageManager.shutdown();
Exception in thread "MicroStream-StorageBackupHandler" one.microstream.storage.exceptions.StorageExceptionBackupCopying: storage/channel_2/channel_2_1.dat@236+0 -> backup/channel_2/channel_2_1.dat
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:471)
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:485)
	at one.microstream.storage.types.StorageBackupItemQueue$Default$Item.processBy(StorageBackupItemQueue.java:178)
	at one.microstream.storage.types.StorageBackupItemQueue$Default.processNextItem(StorageBackupItemQueue.java:109)
	at one.microstream.storage.types.StorageBackupHandler$Default.run(StorageBackupHandler.java:212)
	at java.lang.Thread.run(Thread.java:748)
Caused by: one.microstream.storage.exceptions.StorageExceptionBackupCopying: storage/channel_2/channel_2_1.dat@236+0 -> backup/channel_2/channel_2_1.dat
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:462)
	... 5 more
Caused by: one.microstream.storage.exceptions.StorageExceptionIoReading
	at one.microstream.storage.types.StorageFileEntityDataIterator$Default.fillBuffer(StorageFileEntityDataIterator.java:174)
	at one.microstream.storage.types.StorageFileEntityDataIterator$Internal.iterateEntityData(StorageFileEntityDataIterator.java:45)
	at one.microstream.storage.types.StorageDataFileValidator$Default.validateFile(StorageDataFileValidator.java:112)
	at one.microstream.storage.types.StorageBackupHandler$Default.copyFilePart(StorageBackupHandler.java:457)
	... 5 more
Caused by: one.microstream.storage.exceptions.StorageExceptionIoReading
	at one.microstream.storage.types.StorageFile$Abstract.readBytes(StorageFile.java:149)
	at one.microstream.storage.types.StorageFileEntityDataIterator$Default.fillBuffer(StorageFileEntityDataIterator.java:170)
	... 8 more
Caused by: one.microstream.exceptions.IndexBoundsException: Index out of bounds: 236 not in [0;236[ (StartIndex >= bound)
	at one.microstream.io.XIO.internalRead(XIO.java:1176)
	at one.microstream.io.XIO.read(XIO.java:1162)
	at one.microstream.afs.nio.NioIoHandler$Default.specificReadBytes(NioIoHandler.java:372)
	at one.microstream.afs.nio.NioIoHandler$Default.specificReadBytes(NioIoHandler.java:1)
	at one.microstream.afs.AIoHandler$Abstract.readBytes(AIoHandler.java:752)
	at one.microstream.afs.AReadableFile.readBytes(AReadableFile.java:84)
	at one.microstream.storage.types.StorageFile$Abstract.readBytes(StorageFile.java:145)
	... 9 more
Exception in thread "MicroStream-StorageChannel-0" one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_2/channel_2_1.dat@236+0 -> backup/channel_2/channel_2_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:398)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:475)
	at java.lang.Thread.run(Thread.java:748)
Exception in thread "MicroStream-StorageChannel-3" one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_2/channel_2_1.dat@236+0 -> backup/channel_2/channel_2_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:398)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:475)
	at java.lang.Thread.run(Thread.java:748)
Exception in thread "MicroStream-StorageChannel-2" one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_2/channel_2_1.dat@236+0 -> backup/channel_2/channel_2_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:398)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:475)
	at java.lang.Thread.run(Thread.java:748)
Exception in thread "MicroStream-StorageChannel-1" one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_2/channel_2_1.dat@236+0 -> backup/channel_2/channel_2_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageChannel$Default.work(StorageChannel.java:398)
	at one.microstream.storage.types.StorageChannel$Default.run(StorageChannel.java:475)
	at java.lang.Thread.run(Thread.java:748)
Exception in thread "main" one.microstream.storage.exceptions.StorageExceptionDisruptingExceptions: Disruptions: {one.microstream.storage.exceptions.StorageExceptionBackupCopying:storage/channel_2/channel_2_1.dat@236+0 -> backup/channel_2/channel_2_1.dat,}
	at one.microstream.storage.types.StorageOperationController$Default.checkProcessingEnabled(StorageOperationController.java:119)
	at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTask(StorageTaskBroker.java:189)
	at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTask(StorageTaskBroker.java:176)
	at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTaskAndNotifyAll(StorageTaskBroker.java:166)
	at one.microstream.storage.types.StorageTaskBroker$Default.issueChannelShutdown(StorageTaskBroker.java:453)
	at one.microstream.storage.types.StorageSystem$Default.internalShutdown(StorageSystem.java:499)
	at one.microstream.storage.types.StorageSystem$Default.shutdown(StorageSystem.java:585)
	at one.microstream.storage.types.EmbeddedStorageManager$Default.shutdown(EmbeddedStorageManager.java:348)
	at test.microstream.Test.main(Test.java:42)

@hg-ms
Copy link
Contributor

hg-ms commented Sep 24, 2020

Some additional observations:
The IndexBoundsException: Index out of bounds: 236 not in [0;236[ (StartIndex >= bound) exceptions happen reliable at the first run of fh’s code-example.

To get the one.microstream.exceptions.IndexBoundsException: Index out of bounds: 0 not in [0;0[ (StartIndex >= bound) exception with fh’s code I need do disable the Backup and run it three times.
After the second run I can see that a 0-Byte sized storage data file remains in one channels directory.
If I set the housekeeping use-ratio to a very low value the exception does appear.
Additional the exception and the 0-Byte sized file are gone if I wait a second before the storage.shutdown() is called.

@fh-ms
Copy link
Contributor

fh-ms commented Sep 28, 2020

Further debugging showed the following:
In StorageFileManager#Default#storeChunks is a check if the given ByteBuffer[] array is empty. If true the operation gets cancelled. The error occurs if the given array consists of a single, empty ByteBuffer. Then the routine continues and later on the attempt to write 'nothing' raises the error.

@fh-ms
Copy link
Contributor

fh-ms commented Sep 28, 2020

Actually, the problem is caused when 0 bytes are read from a file.
I compared the pre-AFS behaviour with the current. Without the AFS-detour the 0 byte reads had no effect, because the FileChannel implementations just return, when length == 0. The XIO#read methods, which are called by the NIO AFS implementation, have range checks, which throw an error if a 0 byte read at the end of a file is attempted.
A simple check in XIO#internalRead, which mimics the FileChannel behaviour, resolves the problem.

Nevertheless it should be investigated, what causes the empty writes and reads, or what purpose they serve.

@hg-ms
Copy link
Contributor

hg-ms commented Sep 29, 2020

The Zero-sized file is created during housekeeping in the second run:
After the store operation the channel_0_1.dat file needs dissolving. Thus, a new and empty file (channel_0_2.dat) is created. (one.microstream.storage.types.StorageFileManager.Default.internalCheckForCleanup(long, StorageDataFileDissolvingEvaluator). But no data is copied to that new file because the storage shutdown happens immediately. On the third run this empty file causes the Index out of bounds: 0 not in [0;0[ exception.

@zdenek-jonas
Copy link
Contributor

Ich kann das nicht mehr nachvolziehen. Ok

@fh-ms fh-ms transferred this issue from another repository Apr 27, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants