libsql icon indicating copy to clipboard operation
libsql copied to clipboard

libsql: add `durable_frame_num` caching and metadata file

Open LucioFranco opened this issue 1 year ago • 3 comments

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!

LucioFranco avatar Nov 19 '24 20:11 LucioFranco

@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 avatar Nov 19 '24 20:11 LucioFranco

@LucioFranco What happens if the metadata file is corrupted? The code should recover from that by trying to push the whole log.

penberg avatar Nov 20 '24 15:11 penberg

@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 avatar Nov 21 '24 09:11 penberg

@penberg that has been fixed/implemented and there are a bunch of tests including a corrupted metadata file.

LucioFranco avatar Nov 21 '24 19:11 LucioFranco