libsql: add `durable_frame_num` caching and metadata file
This PR adds both a metadata file that is used to cache the durable_frame_num to allow us to only send the frames the server needs. This also adds some basic logging to allow us to track what frames and generations are being pushed to the server.
Closes #1818
❯ RUST_LOG=libsql::sync=debug cargo run --example offline_writes
Blocking waiting for file lock on build directory
Compiling libsql v0.6.0 (/home/lucio/code/libsql/libsql)
Finished `dev` profile [unoptimized + debuginfo] target(s) in 10.14s
Running `target/debug/examples/offline_writes`
2024-11-19T19:57:20.054954Z DEBUG libsql::sync: no metadata info file found
Please write your entry to the guestbook:
hello
You entered: hello
Guest book entries:
cargo run --example offline_writeshello
hello
hello
hello
hello
Syncing database to remote...
2024-11-19T19:57:23.677365Z DEBUG push_one_frame{generation=1 frame_no=1}: libsql::sync: pushing frame
2024-11-19T19:57:23.781639Z DEBUG push_one_frame{generation=1 frame_no=1}: libsql::sync: frame successfully pushed durable_frame_num=6
2024-11-19T19:57:23.781975Z DEBUG push_one_frame{generation=1 frame_no=7}: libsql::sync: pushing frame
2024-11-19T19:57:23.837472Z DEBUG push_one_frame{generation=1 frame_no=7}: libsql::sync: frame successfully pushed durable_frame_num=6
Done!
libsql on lucio/cache-server-frame [$!?] via 🦀 v1.81.0
❯ RUST_LOG=libsql::sync=debug cargo run --example offline_writes
Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.23s
Running `target/debug/examples/offline_writes`
Please write your entry to the guestbook:
bye
You entered: bye
Guest book entries:
cargo run --example offline_writeshello
hello
hello
hello
hello
bye
Syncing database to remote...
2024-11-19T19:57:42.074752Z DEBUG push_one_frame{generation=1 frame_no=7}: libsql::sync: pushing frame
2024-11-19T19:57:42.118522Z DEBUG push_one_frame{generation=1 frame_no=7}: libsql::sync: frame successfully pushed durable_frame_num=7
2024-11-19T19:57:42.118936Z DEBUG push_one_frame{generation=1 frame_no=8}: libsql::sync: pushing frame
2024-11-19T19:57:42.162425Z DEBUG push_one_frame{generation=1 frame_no=8}: libsql::sync: frame successfully pushed durable_frame_num=7
Done!
@penberg in the logs above I see it is re-sending frame 7 because the server on the previous call returned max_frame_no 6 when we sent frame_no 7. Is there an off by one on the server side or is that to be expected with the protocol?
@LucioFranco What happens if the metadata file is corrupted? The code should recover from that by trying to push the whole log.
@LucioFranco I corrupted the info file as follows:
{"hash":3168545583"version":0,"durable_frame_num":120,"generation":1}
and now I see this error:
Running `/Users/penberg/src/tursodatabase/libsql/target/debug/examples/offline_writes`
thread 'main' panicked at /Users/penberg/src/tursodatabase/libsql/libsql/src/sync.rs:161:78:
called `Result::unwrap()` on an `Err` value: Error("expected `,` or `}`", line: 1, column: 19)
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
As I said before, the info file is for caching purposes. If we fail to read it, we should just discard it and regenerate it after chatting with the server.
@penberg that has been fixed/implemented and there are a bunch of tests including a corrupted metadata file.