concurrent calls to `.clear()` and the ingestion API causes crash and corruption

[svix-jbrown]

Describe the bug
Given the following program:

use anyhow::Context;

fn main() -> anyhow::Result<()> {
    env_logger::init();

    let db = fjall::Database::builder("./db")
        .max_journaling_size(67108864)
        .open()
        .context("opening database")?;

    std::thread::scope(|spawner| {
        let keyspace = db
            .keyspace("keyspace1", fjall::KeyspaceCreateOptions::default)
            .unwrap();

        spawner.spawn({
            let keyspace = keyspace.clone();
            move || -> anyhow::Result<()> {
                for _ in 0..1000 {
                    log::debug!("clearing");
                    keyspace.clear()?;
                    std::thread::sleep(std::time::Duration::from_millis(10));
                }
                Ok(())
            }
        });

        spawner.spawn({
            let keyspace = keyspace.clone();
            move || -> anyhow::Result<()> {
                for _ in 0..1000 {
                    let mut igst = keyspace.start_ingestion()?;
                    for i in 0..=10240 {
                        igst.write(format!("key{i:09}"), [(i % 256) as u8; 256])?;
                    }
                    igst.finish()?;
                }
                Ok(())
            }
        });
    });
    Ok(())
}

If run for a while, it will eventually crash with

thread 'fjall:worker' (8070867) panicked at /Users/jbrown/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/lsm-tree-3.1.4/src/version/mod.rs:572:9:
assertion `left == right` failed: invalid table IDs
  left: 0
 right: 1
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

At this point, the database seems to be mildly corrupted; subsequent startups will hang for ~20s logging nothing and then proceed normally, but will leak thousands of versions in to the db/keyspaces/1/ directory (which will all be truncated on the next startup).

I've attached a database that's in this state, in case that's helpful for debugging.

db_invalid.tar.gz

For whatever reason, the crash seems to occur much faster if you set manual_journal_persist(true) on the KeyspaceCreateOptions, but it does still happen eventually even with default journal persistence.

[marvin-j97]

I do kind of regret even creating a clear() method because it's kind of an awkward operation internally. I'd actually recommend dropping and creating a new keyspace, I think that's the preferred way in RocksDB as well.

[svix-jbrown]

clear is so convenient, though, because then I don't need to track down all of the handles for the Keyspace everywhere and reconnect them when I clear it. :-)

[Boog900]

I think I have hit the same error but it wasn't with the ingestion API, it was just with clear and a natural memtable rotation, which then partially reversed the clear.

Here is a PoC:

use fjall::{Database, KeyspaceCreateOptions};
use std::{thread, time::Duration};

fn main() -> Result<(), Box<dyn std::error::Error>> {
    for attempt in 0..200 {
        let db = Database::builder("./db").open()?;
        let tree = db.keyspace("race", || {
            KeyspaceCreateOptions::default().max_memtable_size(4 * 1024)
        })?;

        let value = vec![b'x'; 16 * 1024];

        for i in 0..2_000u32 {
            tree.insert(format!("old-{i:08}"), value.as_slice())?;
        }

        tree.clear()?;

        for i in 0..10u32 {
            tree.insert(format!("new-{i:08}"), b"new")?;
        }

        for _ in 0..200 {
            let len = tree.len()?;
            if len > 10 {
                println!("reproduced attempt={attempt} len={len}");
                println!("first={:?}", tree.first_key_value().map(|g|String::from_utf8(g.key().unwrap().to_vec()).unwrap()));
                println!("last={:?}", tree.last_key_value().map(|g| String::from_utf8(g.key().unwrap().to_vec()).unwrap()));
                return Ok(());
            }

            thread::sleep(Duration::from_millis(10));
        }

        if attempt % 10 == 0 {
            println!("attempt={attempt} ok");
        }
    }

    println!("no repro");
    Ok(())
}

Here are some outputs:

reproduced attempt=0 len=11
first=Some("new-00000000")
last=Some("old-00001770")

reproduced attempt=0 len=12
first=Some("new-00000000")
last=Some("old-00001970")

attempt=0 ok
reproduced attempt=1 len=15
first=Some("new-00000000")
last=Some("old-00001994")

[marvin-j97]

@Boog900 I think your issue is another one and seems to be a race condition when using clear() and having active flushes.
Can you try this diff?: fjall-rs/lsm-tree#303

[Boog900]

Ah, my bad, yes that patch does seem to fix it