Intermittent problem when opening database

[HansITChange]

I'm running version 1.4.0, however this problem was also present in previous versions. Now and then, I get following error:

Error occurred in storage channel#0
org.eclipse.store.storage.exceptions.StorageExceptionIoWriting: null
	at org.eclipse.store.storage.types.StorageFileWriter.truncateFile(StorageFileWriter.java:168)
	at org.eclipse.store.storage.types.StorageFileWriter.truncate(StorageFileWriter.java:144)
	at org.eclipse.store.storage.types.StorageFileManager$Default.handleLastFile(StorageFileManager.java:1304)
	at org.eclipse.store.storage.types.StorageFileManager$Default.initializeForExistingFiles(StorageFileManager.java:1011)
	at org.eclipse.store.storage.types.StorageFileManager$Default.initializeStorage(StorageFileManager.java:886)
	at org.eclipse.store.storage.types.StorageChannel$Default.initializeStorage(StorageChannel.java:782)
	at org.eclipse.store.storage.types.StorageChannelTaskInitialize$Default.succeed(StorageChannelTaskInitialize.java:200)
	at org.eclipse.store.storage.types.StorageChannelTaskInitialize$Default.succeed(StorageChannelTaskInitialize.java:34)
	at org.eclipse.store.storage.types.StorageChannelSynchronizingTask$AbstractCompletingTask.synchronizedComplete(StorageChannelSynchronizingTask.java:78)
	at org.eclipse.store.storage.types.StorageChannelSynchronizingTask$AbstractCompletingTask.complete(StorageChannelSynchronizingTask.java:126)
	at org.eclipse.store.storage.types.StorageChannelTask$Abstract.processBy(StorageChannelTask.java:260)
	at org.eclipse.store.storage.types.StorageChannel$Default.work(StorageChannel.java:453)
	at org.eclipse.store.storage.types.StorageChannel$Default.run(StorageChannel.java:536)
	at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: org.eclipse.store.storage.exceptions.StorageExceptionConsistency: Reopened file has inconsistent size: Expected size 50962 != actual size 51066.
	at org.eclipse.store.storage.types.StorageLiveDataFile$Default.internalOpenWriting(StorageLiveDataFile.java:282)
	at org.eclipse.store.storage.types.StorageFile$Abstract.ensureWritable(StorageFile.java:390)
	at org.eclipse.store.storage.types.StorageFile$Abstract.truncate(StorageFile.java:366)
	at org.eclipse.store.storage.types.StorageFileWriter.truncateFile(StorageFileWriter.java:164)

Where is this coming from ?
And how can I recover from this error ? The only way I found was to empty the database, and start all over... Is there a more intelligent way to recover from this error ?

[hg-ms]

To investigate the issue, we need some more information:

• What kind of storage target are your using?
• If using a NioFileSystem which one? Is it a local one ore a remote one?
• can you provide the storage initialization code?
• Can you provide the transaction log files?

[HansITChange]

Storage target: MariaDB

Storage initialization code:

public class Database {
	private static final Logger LOG = LoggerFactory.getLogger(Database.class);
	private static Database instance = null;
	public volatile static EmbeddedStorageManager storageManager = null;
	
	public volatile static GenericRepository<User> userRepository=null;
	public volatile static GenericRepository<Patient> patientRepository=null;

	public static Database getInstance(String env) {
		if (instance == null) {
			synchronized (Database.class) {
				if (instance == null) {
					CurrentPatient.getInstance();
					instance = new Database(env);
				}
			}
		}
		return instance;
	}

	private Database(String env) {
		if (storageManager == null) {
			LOG.info("Initialising database");
			try {
				Configuration conf = Configuration.getInstance();
				String dbURL  = Encryption.decrypt(conf.getValue("DBURL"  + env));
				String dbUSER = Encryption.decrypt(conf.getValue("DBUSER" + env));
				String dbPASS = Encryption.decrypt(conf.getValue("DBPASS" + env));
				
				MariaDbDataSource dataSource = new MariaDbDataSource();
				dataSource.setUrl(dbURL+"?user="+dbUSER+"&password="+dbPASS);
				SqlFileSystem fileSystem = SqlFileSystem.New(SqlConnector.Caching(SqlProviderMariaDb.New(dataSource)));
				storageManager = EmbeddedStorage.start(fileSystem.ensureDirectoryPath("microstream_storage"));

				if (storageManager.root() == null) {
					LOG.info("Creating structure in database");
					Root root = new Root();
					storageManager.setRoot(root);
					storageManager.storeRoot();
				}
			} catch (Exception e) {
				LOG.error("Error decrypting database credentials", e);
			}
		}
		initializeRepositories();
	}
	
	private void initializeRepositories() {
		Root root = (Root) storageManager.root();
		userRepository = new GenericRepository<>(storageManager, root.getUsers());
		patientRepository = new GenericRepository<>(storageManager, root.getPatients());
		if (root.getUsers().isEmpty()) {
            root.populate(storageManager);
            storageManager.store(root);
        } 

	}

	public static EmbeddedStorageManager getStorageManager() {
		return storageManager;
	}

	public static GenericRepository<User> getUserRepository() {
		return userRepository;
	}
	
	public static GenericRepository<Patient> getPatientRepository() {
		return patientRepository;
	}
	
	public static void shutdown() {
        if (storageManager != null) {
            storageManager.shutdown();
            LOG.info("Storage manager shutdown completed");
        }
    }
	
}

and the code for the genericRepository class:

public class GenericRepository<T extends Identifiable> {
	private static final Logger LOG = LoggerFactory.getLogger(GenericRepository.class);
	private final EmbeddedStorageManager storageManager;
	private final List<T> collection;

	public GenericRepository(EmbeddedStorageManager storageManager, List<T> collection) {
		this.storageManager = storageManager;
		this.collection = collection;
	}

	public List<T> getCollection() {
		return collection;
	}

	public static <T extends Identifiable> long findMaxId(List<T> collection) {
		OptionalLong id = collection.stream().mapToLong(Identifiable::getId).max();
		return id.orElse(0L);
	}

	public void create(T object) {
		long id = findMaxId(collection) + 1L;
		object.setId(id);
		LOG.info("Creating " + object.getTable() + " id: " + object.getId());
		collection.add(object);
		storageManager.store(collection);
	}

	public T read(Long id) {
		return collection.stream().filter(obj -> {
			try {
				Field idField = obj.getClass().getDeclaredField("id");
				idField.setAccessible(true);
				return id.equals(idField.get(obj));
			} catch (Exception e) {
				LOG.error("Error accessing id field", e);
				return false;
			}
		}).findFirst().orElse(null);
	}

	public T readByAttribute(String attributeName, Object attributeValue) {
		return collection.stream().filter(obj -> {
			try {
				Field field = obj.getClass().getDeclaredField(attributeName);
				field.setAccessible(true);
				return attributeValue.equals(field.get(obj));
			} catch (Exception e) {
				LOG.error("Error accessing attribute field", e);
				return false;
			}
		}).findFirst().orElse(null);
	}

	public void update(T updatedObject) {
		// Find the existing object by ID
		try {
			LOG.info("Start of update");
			LOG.info(updatedObject.toString());

			LOG.info("--");
			var getIdMethod = updatedObject.getClass().getMethod("getId");
			Long id = (Long) getIdMethod.invoke(updatedObject);
			T existingObject = read(id);
			if (!(existingObject == null)) {
				// Replace the existing object with the updated object
				LOG.info("Updating " + existingObject.getTable() + " id: " + existingObject.getId() + " index: "
						+ collection.indexOf(existingObject));
				int index = collection.indexOf(existingObject);
				LOG.info("index: "+index);
				collection.set(index, updatedObject);
				storageManager.store(collection);
			} else {
				throw new RuntimeException("Object not found");
			}
			LOG.info("End of update");
			for (T c : collection) {
				LOG.info(c.toString());
			}

			LOG.info("--");
		} catch (Exception e) {
			throw new RuntimeException("Failed to update the object", e);
		}
	}

	public void delete(Long id) {
		// Find the existing object by ID
		T existingObject = read(id);
		if (!(existingObject == null)) {
			// Remove the object from the root collection
			LOG.info("Deleting " + existingObject.getTable() + " id: " + existingObject.getId());
			collection.remove(existingObject);
			storageManager.store(collection);
		} else {
			throw new RuntimeException("Object not found");
		}
	}

	public ObservableList<T> getAllAsObservableList() {
		return FXCollections.observableArrayList(collection);
	}

	public boolean exists(T object) {
		if (object.getId() > 0L)
			return true;
		return false;
	}

	public List<String> store(T object) {
		List<String> errors = object.validate();
		if (errors == null || errors.isEmpty()) {
			if (object.getId() == 0L)
				create(object);
			else
				update(object);
			MDData.setChanged(false);
			return null;
		} else
			return errors;
	}
}

I don't have transaction log files, or are these somewhere by default ?

[hg-ms]

Thanks for the additional info and code.
The transaction log is stored as blobs in the db. It's quite cumbersome to get it, but I was able to reproduce the exception without it.

Looks like a bug.

[HansITChange]

ok. thanks for the help so far... is there anything I could do to avoid this bug ?

[hg-ms]

The problem is caused by an incomplete store that can’t be reverted if the SqlConnector is used.
This must be fixed in the EclipseStore code.

To avoid such incomplete stores, you should always shutdown the storage using the shutdown() method before terminating your app.

Maybe you can try to repair the storage by truncating the storage data manually.
To do so you need to look for a table named "microstream_storage$channel_0" in the db.
This table should have entries with identifiers like “channel_0_n.dat”. Look for the identifier that has the greatest number “n” and delete all entries that have a “start” value greater or equals 50962 (the last known valid size).

[HansITChange]

Ok, thanks. I'll try this out whenever I have the same problem again, and will keep you posted.