Use sled Database to persist data

[DanGould]

TL;DR We keep including more and more persistent state in a miscellaneous .json files. An embedded db gives us the opportunity to fix this.

We need to make async payjoin-cli sessions pleasant to use.

Using payjoin-cli completely asynchronously, including program shutdowns, is a bit clunky and subject to at least one complaint #267.

I revisited the experience by recording a screenshare of doing it and have to say I agree. There are a few problems:

1. Only a single send and receive session are ever saved and not overwritten
2. The sessions don't properly expire
3. A manual --retry flag is required to resume a prior session

This change is the first of a handful of changes to fix this problem. By using a database, we can handle persistent data in a single file and interact with high performance. To provide a good experience we'll want to address each of the above issues.

1. Persist multiple payjoin sessions and resume them as appropriate
2. Expire sessions that will not complete
3. Automate session resumption when the program comes back online

By addressing these and later including our solutions in the io feature we can create a reference implementation and toolkit for consumers to implement Payjoin V2 easily and appropriately.

This is the first step to fix the payjoin-cli async experience problem.

[DanGould]

Note, this database structure is almost definitely not what we'll end up using long term, but 1. payjoin sessions are short-lived, and losing them doesn't cause a huge disruption 2. we're in alpha anyway, so we can tolerate this kind of breaking change and 3. I plan to have a better structure out before we release payjoin-cli-0.0.7-alpha. Working on that immediately after this as a follow up.

[spacebear21]

I'm unable to resume an existing session with either the receiver or sender with --retry. The payjoin.sled directory exists where I'm running the command and the session appears to have been inserted successfully in the first step. Possibly related to my comment below on get_recv/send_session?

❯ RUST_LOG=debug cargo run --features=v2 -- receive 10000

[2024-06-18T16:29:56Z DEBUG payjoin_cli::app::config] App config: AppConfig { bitcoind_rpchost: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(18443), path: "/wallet/receive", query: None, fragment: None }, bitcoind_cookie: None, bitcoind_rpcuser: "payjoin", bitcoind_rpcpassword: "payjoin", db_path: "payjoin.sled", ohttp_keys: None, ohttp_relay: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("pj.bobspacebkk.com")), port: None, path: "/", query: None, fragment: None }, pj_directory: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("payjo.in")), port: None, path: "/", query: None, fragment: None } }
[2024-06-18T16:29:56Z DEBUG sled::pagecache::snapshot] no previous snapshot found
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iterator] ordering before clearing tears: {}, max_header_stable_lsn: 0
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iterator] in clean_tail_tears, found missing item in tail: None and we'll scan segments {} above lowest lsn 0
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" })
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iterator] filtering out segments after detected tear at (lsn, lid) -1
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iterator] unable to load new segment: Io(Custom { kind: Other, error: "no segments remaining to iterate over" })
[2024-06-18T16:29:56Z DEBUG sled::pagecache::segment] SA starting with tip 0 stable -1 free {}
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] starting log for a totally fresh system
[2024-06-18T16:29:56Z DEBUG sled::pagecache::segment] segment accountant returning offset: 0 for lsn 0 on deck: {}
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] starting IoBufs with next_lsn: 0 next_lid: 0
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] storing lsn 0 in beginning of buffer
[2024-06-18T16:29:56Z DEBUG sled::pagecache] load_snapshot loading pages from 0..0
[2024-06-18T16:29:56Z DEBUG sled::meta] allocated pid 3 for root of new_tree [95, 95, 115, 108, 101, 100, 95, 95, 100, 101, 102, 97, 117, 108, 116]
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] advancing offset within the current segment from 0 to 71
[2024-06-18T16:29:56Z DEBUG bitcoincore_rpc] JSON-RPC request: getblockchaininfo []
[2024-06-18T16:29:56Z DEBUG bitcoincore_rpc] JSON-RPC request: getnetworkinfo []
Bootstrapping private network transport over Oblivious HTTP
[2024-06-18T16:29:56Z DEBUG reqwest::connect] starting new connection: https://payjo.in/
[2024-06-18T16:29:56Z DEBUG reqwest::connect] proxy(https://pj.bobspacebkk.com) intercepts 'https://payjo.in/'
[2024-06-18T16:29:56Z DEBUG hyper_util::client::legacy::connect::dns] resolving host="pj.bobspacebkk.com"
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] wrote lsns 0-70 to disk at offsets 0-70, maxed false complete_len 71
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] mark_interval(0, 71)
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] new highest interval: 0 - 70
[2024-06-18T16:29:56Z DEBUG hyper_util::client::legacy::connect::http] connecting to 157.245.59.46:443
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] advancing offset within the current segment from 71 to 96
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] wrote lsns 71-95 to disk at offsets 71-95, maxed false complete_len 25
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] mark_interval(71, 25)
[2024-06-18T16:29:56Z DEBUG sled::pagecache::iobuf] new highest interval: 71 - 95
[2024-06-18T16:29:56Z DEBUG hyper_util::client::legacy::connect::http] connected to 157.245.59.46:443
[2024-06-18T16:29:56Z DEBUG rustls::client::hs] No cached session for DnsName("pj.bobspacebkk.com")
[2024-06-18T16:29:56Z DEBUG rustls::client::hs] Not resuming any session
[2024-06-18T16:29:57Z DEBUG rustls::client::hs] ALPN protocol is None
[2024-06-18T16:29:57Z DEBUG rustls::client::hs] Using ciphersuite TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384
[2024-06-18T16:29:57Z DEBUG rustls::client::tls12::server_hello] Server supports tickets
[2024-06-18T16:29:57Z DEBUG rustls::client::tls12] ECDHE curve is EcParameters { curve_type: NamedCurve, named_group: X25519 }
[2024-06-18T16:29:57Z DEBUG rustls::client::tls12] Server DNS name is DnsName("pj.bobspacebkk.com")
[2024-06-18T16:29:58Z DEBUG rustls::client::hs] No cached session for DnsName("payjo.in")
[2024-06-18T16:29:58Z DEBUG rustls::client::hs] Not resuming any session
[2024-06-18T16:29:59Z DEBUG rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384
[2024-06-18T16:29:59Z DEBUG rustls::client::tls13] Not resuming
[2024-06-18T16:29:59Z DEBUG rustls::client::tls13] TLS1.3 encrypted extensions: [ServerNameAck, Protocols([ProtocolName(687474702f312e31)])]
[2024-06-18T16:29:59Z DEBUG rustls::client::hs] ALPN protocol is Some(b"http/1.1")
[2024-06-18T16:30:01Z DEBUG hyper_util::client::legacy::pool] pooling idle connection for ("https", payjo.in)
[2024-06-18T16:30:01Z DEBUG rustls::common_state] Sending warning alert CloseNotify
[2024-06-18T16:30:01Z DEBUG rustls::common_state] Sending warning alert CloseNotify
Starting new Payjoin session with https://payjo.in/
[2024-06-18T16:30:01Z DEBUG reqwest::connect] starting new connection: https://pj.bobspacebkk.com/
[2024-06-18T16:30:01Z DEBUG hyper_util::client::legacy::connect::dns] resolving host="pj.bobspacebkk.com"
[2024-06-18T16:30:01Z DEBUG hyper_util::client::legacy::connect::http] connecting to 157.245.59.46:443
[2024-06-18T16:30:01Z DEBUG hyper_util::client::legacy::connect::http] connected to 157.245.59.46:443
[2024-06-18T16:30:01Z DEBUG rustls::client::hs] No cached session for DnsName("pj.bobspacebkk.com")
[2024-06-18T16:30:01Z DEBUG rustls::client::hs] Not resuming any session
[2024-06-18T16:30:02Z DEBUG rustls::client::hs] ALPN protocol is None
[2024-06-18T16:30:02Z DEBUG rustls::client::hs] Using ciphersuite TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384
[2024-06-18T16:30:02Z DEBUG rustls::client::tls12::server_hello] Server supports tickets
[2024-06-18T16:30:02Z DEBUG rustls::client::tls12] ECDHE curve is EcParameters { curve_type: NamedCurve, named_group: X25519 }
[2024-06-18T16:30:02Z DEBUG rustls::client::tls12] Server DNS name is DnsName("pj.bobspacebkk.com")
[2024-06-18T16:30:03Z DEBUG hyper_util::client::legacy::pool] pooling idle connection for ("https", pj.bobspacebkk.com)
[2024-06-18T16:30:03Z DEBUG sled::pagecache::iobuf] advancing offset within the current segment from 96 to 361
[2024-06-18T16:30:04Z DEBUG sled::pagecache::iobuf] wrote lsns 96-360 to disk at offsets 96-360, maxed false complete_len 265
[2024-06-18T16:30:04Z DEBUG sled::pagecache::iobuf] mark_interval(96, 265)
[2024-06-18T16:30:04Z DEBUG sled::pagecache::iobuf] new highest interval: 96 - 360
[2024-06-18T16:30:04Z DEBUG sled::pagecache::iobuf] make_stable(360) returning
Receive session established
[2024-06-18T16:30:04Z DEBUG rustls::common_state] Sending warning alert CloseNotify
[2024-06-18T16:30:04Z DEBUG bitcoincore_rpc] JSON-RPC request: getnewaddress [null,null]
Request Payjoin by sharing this Payjoin Uri:
bitcoin:bcrt1qvj33vk8p5qxgfpmaslr3mjmwhpn48j0e280dur?amount=0.0001&pj=https://payjo.in/Apcyel6rcOWnTk_4mZlbMZI-ohVxSd46bjIvGYSwCkV0&pjos=0&ohttp=AQAgbLIT3-hgHP5dAGB574bdCyTeJvJR4n7hLJ4B8dxgYDMABAABAAM
Polling receive request...

❯ RUST_LOG=debug cargo run --features=v2 -- --retry receive 10000

[2024-06-18T16:32:23Z DEBUG payjoin_cli::app::config] App config: AppConfig { bitcoind_rpchost: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(18443), path: "/wallet/receive", query: None, fragment: None }, bitcoind_cookie: None, bitcoind_rpcuser: "payjoin", bitcoind_rpcpassword: "payjoin", db_path: "payjoin.sled", ohttp_keys: None, ohttp_relay: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("pj.bobspacebkk.com")), port: None, path: "/", query: None, fragment: None }, pj_directory: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("payjo.in")), port: None, path: "/", query: None, fragment: None } }
[2024-06-18T16:32:23Z DEBUG sled::pagecache::snapshot] no previous snapshot found
[2024-06-18T16:32:23Z DEBUG sled::pagecache::iterator] ordering before clearing tears: {0: 0}, max_header_stable_lsn: 0
[2024-06-18T16:32:23Z DEBUG sled::pagecache::iterator] in clean_tail_tears, found missing item in tail: None and we'll scan segments {0: 0} above lowest lsn 0
[2024-06-18T16:32:23Z DEBUG sled::pagecache::iterator] filtering out segments after detected tear at (lsn, lid) 360
[2024-06-18T16:32:23Z DEBUG sled::pagecache::iterator] hit max_lsn 360 in iterator, stopping
[2024-06-18T16:32:23Z DEBUG sled::pagecache::snapshot] zeroing the end of the recovered segment at lsn 0 between lids 361 and 524287
[2024-06-18T16:32:24Z DEBUG sled::pagecache::blob_io] gc_blobs removing any blob with an lsn above 361
[2024-06-18T16:32:24Z DEBUG sled::pagecache::segment] SA starting with tip 524288 stable -1 free {}
[2024-06-18T16:32:24Z DEBUG sled::pagecache::iobuf] starting log at recovered active offset 361, recovered lsn 361
[2024-06-18T16:32:24Z DEBUG sled::pagecache::iobuf] starting IoBufs with next_lsn: 361 next_lid: 361
[2024-06-18T16:32:24Z DEBUG sled::pagecache] load_snapshot loading pages from 0..4
[2024-06-18T16:32:24Z DEBUG bitcoincore_rpc] JSON-RPC request: getblockchaininfo []
[2024-06-18T16:32:24Z DEBUG bitcoincore_rpc] JSON-RPC request: getnetworkinfo []
Bootstrapping private network transport over Oblivious HTTP
[2024-06-18T16:32:24Z DEBUG reqwest::connect] starting new connection: https://payjo.in/
[2024-06-18T16:32:24Z DEBUG reqwest::connect] proxy(https://pj.bobspacebkk.com) intercepts 'https://payjo.in/'
[2024-06-18T16:32:24Z DEBUG hyper_util::client::legacy::connect::dns] resolving host="pj.bobspacebkk.com"
[2024-06-18T16:32:24Z DEBUG hyper_util::client::legacy::connect::http] connecting to 157.245.59.46:443
[2024-06-18T16:32:24Z DEBUG hyper_util::client::legacy::connect::http] connected to 157.245.59.46:443
[2024-06-18T16:32:24Z DEBUG rustls::client::hs] No cached session for DnsName("pj.bobspacebkk.com")
[2024-06-18T16:32:24Z DEBUG rustls::client::hs] Not resuming any session
[2024-06-18T16:32:24Z DEBUG rustls::client::hs] ALPN protocol is None
[2024-06-18T16:32:24Z DEBUG rustls::client::hs] Using ciphersuite TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384
[2024-06-18T16:32:24Z DEBUG rustls::client::tls12::server_hello] Server supports tickets
[2024-06-18T16:32:24Z DEBUG rustls::client::tls12] ECDHE curve is EcParameters { curve_type: NamedCurve, named_group: X25519 }
[2024-06-18T16:32:24Z DEBUG rustls::client::tls12] Server DNS name is DnsName("pj.bobspacebkk.com")
[2024-06-18T16:32:25Z DEBUG rustls::client::hs] No cached session for DnsName("payjo.in")
[2024-06-18T16:32:25Z DEBUG rustls::client::hs] Not resuming any session
[2024-06-18T16:32:26Z DEBUG rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384
[2024-06-18T16:32:26Z DEBUG rustls::client::tls13] Not resuming
[2024-06-18T16:32:26Z DEBUG rustls::client::tls13] TLS1.3 encrypted extensions: [ServerNameAck, Protocols([ProtocolName(687474702f312e31)])]
[2024-06-18T16:32:26Z DEBUG rustls::client::hs] ALPN protocol is Some(b"http/1.1")
[2024-06-18T16:32:27Z DEBUG hyper_util::client::legacy::pool] pooling idle connection for ("https", payjo.in)
[2024-06-18T16:32:27Z DEBUG rustls::common_state] Sending warning alert CloseNotify
Resuming Payjoin session
[2024-06-18T16:32:27Z DEBUG rustls::common_state] Sending warning alert CloseNotify
[2024-06-18T16:32:27Z DEBUG sled::pagecache::logger] IoBufs dropped
Error: No session found

[spacebear21]

Do we ever insert an entry with "recv_sessions" as the key? It looks to me like this always returns None. Likewise for "send_sessions".

[DanGould]

I changed 3900859 to store recv_sessions and send_sessions a tree. The other DB get methods just return the first element, and clear still clears. This is prep for #283 and fixes --retry in my manual testing.

Before the next version of payjoin-cli is released to fix async payjoin UX, we're going to need to have a test. I'd like to see an integration test with all of the networking / db implementation in the payjoin/io feature to test it without CLI dependencies. But either payjoin-cli or payjoin integration test would both work. I think we're better off adding the automated test in #283 since the interface is going to change quite a bit.

[spacebear21]

Agreed, I can take a stab at adding the async integration test on top of #283

[spacebear21]

I made an initial attempt at adding this to tests here. Not sure if it's sufficient but it at least catches the error fixed by #284 as it stands.

[DanGould]

@grizznaut I didn't realize you made a PR into the PR branch. Could you open a new one on this repo? DanGould#3 seems like a sound addition to integration tests

[spacebear21]

tACK