Handeling corrupt index

[UpBlueio]

Hi,

Thank your for this great library. We use this library in a datalogger. Due to unexpected power loss the index got corrupted. The program now fails on;
index corrupted: unexpected data len: 118784

How to recover from this? Best case we can recover some of the logs. Worst case the log is not recoverable, in that case i need somehow a method to create a new log database and deleting the old database.

What i can do is purge the old folder and try again, but if there is a better way, let me know.

In our use case the datalogger uses klevdb if somehow there is no connection to the internet. In that scenario it is not unthinkable the program gets a hard reset at some point. Can the library be improved that it can handle hard resets?

Thank your for all your hard work.
Sjoerd

[ingon]

Hi Sjoerd,

Thanks for using klevdb!

I think you have a few options:

• sounds like the head segment index is broken (but not the head segment itself), so you could just delete the last .index file. There is logic that detects that this index is missing and recreate it from the .log file.
• another option is to try klevdb.Recover. It will first rewrite the head .log file up to a consistent point, then recreate the index that corresponds to it.

In any case, take a backup of the folder itself to make sure you have old messages. Let me know if any of these works for you.

[UpBlueio]

Hi Ingon,

Thank you for your fast reply. I created a test that;

• creates a new db,
• writes 100.000 records
• close the database
• removes 00000000000000000000.index
• adds new 00000000000000000000.index with some dummy data
• opens the database again
• get expected error: index corrupted: unexpected data len: 17
• calls new custom function that deletes all .index files
• open db again.
• get unexpected error: "log already locked"

i changed the remove index function to also remove the .lock file, but the file is in use.
It seems the .lock file is not removed when the db cannot be opened

I also wrote the same test, but than instead of removing the indexes, it calls klevdb.Recover. This does not seems to work. The function does not err, but also does not fix the database.

[ingon]

Did you happen to close the log between:

opens the database again
get expected error: index corrupted: unexpected data len: 17
----- close here?
calls new custom function that deletes all .index files

We do have a test that supposedly covers this case in here: https://github.com/klev-dev/klevdb/blob/main/log_test.go#L1034

I'll take a look at reproducing this issue in a different way too

[UpBlueio]

The test at L1034 deletes the index files while the DB is open. In my test, i close the DB, corrupt the index, and reopen the DB. If Reopen fails, the lock is not removed. So if the function deletes the index files after and try to reopen the DB, it fails on the lock.

If the DB errors with "index corrupted: unexpected data len: 17", i cannot close the DB since the DB is nil.

My test code;

func TestWalCacheCorruption(t *testing.T) {
	logger.CreateLogger()
	err := NewWalCacheWithRecover(walCachePathTest)
	assert.NoError(t, err)

	// Publish 100000 messages to the WAL cache
	var msgs []klevdb.Message
	for i := 0; i < 100000; i++ {
		msgs = append(msgs, klevdb.Message{Value: []byte(fmt.Sprintf("test message %d", i+1))})
	}
	err = WalCachePublish(msgs)
	assert.NoError(t, err)
	// Close the WAL cache
	err = WalCacheClose()
	assert.NoError(t, err)
	// Corrupt the WAL cache by deleting it and creating a new one

	err = os.Remove(fmt.Sprintf("%s/fileCache/00000000000000000000.index", walCachePathTest))
	assert.NoError(t, err)

	// Create the index file and write some random characters to it
	file, err := os.Create(fmt.Sprintf("%s/fileCache/00000000000000000000.index", walCachePathTest))
	assert.NoError(t, err)
	_, err = file.WriteString("random characters")
	assert.NoError(t, err)
	err = file.Close()
	assert.NoError(t, err)

	// Reopen the WAL cache
	err = NewWalCacheWithRecover(walCachePathTest)
	assert.NoError(t, err)
	//close the wal cache
	err = WalCacheClose()
	assert.NoError(t, err)
	err = deleteWalCache(walCachePathTest)
	assert.NoError(t, err)
}

My ugly opendb func

func NewWalCacheWithRecover(configPath string) error {
	walCacheMu.Lock()
	defer walCacheMu.Unlock()
	err := newWalCache(configPath)
	time.Sleep(1 * time.Second)
	if err != nil {
		logger.Log.Errorf("Error creating WALcache: %s", err)
		err = walCacheDeleteIndex()
		if err != nil {
			logger.Log.Errorf("Error deleting WALcache index: %s", err)
			return err
		}
		err := newWalCache(configPath)
		if err != nil {
			logger.Log.Errorf("Error creating WALcache, even by deleting the indexes: %s", err)
			return err
		}
		return nil
	}
	return nil
}

[ingon]

The test at L1034 deletes the index files while the DB is open.

It actually does close it, on line #1047.

I'll try to reproduce, but you are right, we shouldn't probably leave the lock if there was an error while opening the wal.

[ingon]

I've made a fix for this behavior over here: #11

Lemme know if this works for you, thanks.

[UpBlueio]

Hi Ingon,

Version v0.7.5 fixes the issue.

Thank you.

[UpBlueio]

Hi Ingon,

Issue is fixed, but i am wondering if the library itself should handle corrupt indexes.

Currently i check for err on klevdb.Open. If err, delete index and try again.

If there are multiple indexes and the first index is corrupt. klevdb.Open works just fine. Only after i use _, msg, err := db.Consume(offset, 2) the function will err.

What i can do if Consumes errors: close db, delete indexes, reopen.
I have two problems with that:

• it is hard to trigger on err. I cannot check if the err is because of index, or some other reason
• Now i have on multiple places logic to fix errors.

my Test:

func TestWalCacheCorruptionDouble(t *testing.T) {
	logger.CreateLogger()

	for j := 0; j < 10; j++ {
		err := NewWalCacheWithRecover(walCachePathTest)
		assert.NoError(t, err)

		// Publish 100000 messages to the WAL cache
		var msgs []klevdb.Message
		for i := 0; i < 100000; i++ {
			msgs = append(msgs, klevdb.Message{Value: []byte(fmt.Sprintf("test message %d", i+1))})
		}
		err = WalCachePublish(msgs)
		assert.NoError(t, err)
		// Close the WAL cache
		err = WalCacheClose()
		assert.NoError(t, err)
	}

	// Corrupt the WAL cache by deleting it and creating a new one

	err := os.Remove(fmt.Sprintf("%s/fileCache/00000000000000000000.index", walCachePathTest))
	assert.NoError(t, err)

	// Create the index file and write some random characters to it
	file, err := os.Create(fmt.Sprintf("%s/fileCache/00000000000000000000.index", walCachePathTest))
	assert.NoError(t, err)
	_, err = file.WriteString("random characters")
	assert.NoError(t, err)
	err = file.Close()
	assert.NoError(t, err)

	err = newWalCache(walCachePathTest)
	assert.NoError(t, err)

	//read from oldest
	_, err = WalCacheConsume(klevdb.OffsetOldest, 2)
	assert.NoError(t, err)
	//close the wal cache
	err = WalCacheClose()
	assert.NoError(t, err)
	err = deleteWalCache(walCachePathTest)
	assert.NoError(t, err)
}

Test fails on WalCacheConsume

[ingon]

I wonder if this is a valid case 🤔 Under normal operations - it could happen for the head index to break (e.g. power loss for example). But the non-head index files will be there completely and not broken, and this is why the library checks the head index only.

Reading all index files eagerly, also introduces non-trivial performance hit on opening the log. While I'm considering an option to check that, you should be able to add this logic yourself - the internals will call segment.ReindexAndReadIndex on each segment to get the index, so you could use that to check if all indexes are good, before opening the index? 🤔

[UpBlueio]

Hi Ingon.

I think you are right.
The software where the problem occurs is running on a machine where i cannot access the files for debugging. I think there are more problems. I deleted the indexes but still klevdb gives errors. Somehow the db got fully corrupted.

I will create a check with ReindexAndReadIndex on read error. Thank you for the advice.