Skip to content

make lwk available - #288

Merged
YusukeShimizu merged 29 commits into
ElementsProject:masterfrom
YusukeShimizu:lwk-swap
Jul 5, 2024
Merged

make lwk available#288
YusukeShimizu merged 29 commits into
ElementsProject:masterfrom
YusukeShimizu:lwk-swap

Conversation

@YusukeShimizu

@YusukeShimizu YusukeShimizu commented Mar 11, 2024

Copy link
Copy Markdown
Contributor

lbtc swap with lwk

Description

Previously, lbtc swap required running elementsd, but now it can be done with lwk.
Because elementsd requires a lot of resources, making it available in lwk will allow more users to perform swaps.

setup

see docs/setup_lwk.md.

Specification

lwk and esplora-electrs connection is required.
New json rpc api client is implemented for connection to lwk.

Connection to esplora-electrs using go-electrum.
esplora-electrs is also used by lwk as a blockchain.

Configuration

The user can choose to use lwk instead of elements for lbtc swap.
It has the following configuration items.

type LWKConf struct {
	SignerName       string
	WalletName       string
	LWKEndpoint      string
	ElementsEndpoint string
	Network          string
	LiquidSwaps      *bool
}

The user can choose to set up a wallet that holds the signer.
Default uses the same default endpoint (blockstream.info:995) as lwk, but the user can choose his own electrum for ElementsEndpoint.

wallet

Peerswap's onchain wallet provide the following features.

type Wallet interface {
	GetAddress() (string, error)
	SendToAddress(string, uint64) (string, error)
	GetBalance() (uint64, error)
	CreateAndBroadcastTransaction(swapParams *swap.OpeningParams, asset []byte) (txid, rawTx string, fee uint64, err error)
	SendRawTx(rawTx string) (txid string, err error)
	GetFee(txSize int64) (uint64, error)
}

GetAddress() (string, error)

This method is used to get the address of the wallet.
Use lwk address.

SendToAddress(string, uint64) (string, error)

This method is used to send money to a specific address.
lwk send to create a psbt, sign to sign it, and broadcast to broadcast it.

CreateAndBroadcastTransaction(swapParams *swap.OpeningParams, asset []byte) (txid, rawTx string, fee uint64, err error)

This method is used to create and broadcast opening tx.
The interface has been split into the following two interfaces,
but they will be merged into a single interface for lwk support.
Existing bitcoin wallets will also be changed, but functionality will remain the same.

CreateFundedTransaction(preparedTx *transaction.Transaction) (rawTx string, fee uint64, err error)
FinalizeFundedTransaction(unpreparedTx string) (preparedTxHex string, err error)

SendRawTx(rawTx string) (txid string, err error)

This method is used to broadcast the closing tx.
This is done using electrum cient's blockchain.transaction.broadcast method.

GetFee(txSize int64) (uint64, error)

This method is used to get the fee blockchain.estimatefee.

tx watcher

tx watcher is a function that monitors onchain status and notifies opening tx and closing tx.
The following interface must be implemented.

type TxWatcher interface {
	AddWaitForConfirmationTx(swapId, txId string, vout, startingHeight uint32, scriptpubkey []byte)
	AddWaitForCsvTx(swapId, txId string, vout uint32, startingHeight uint32, scriptpubkey []byte)
	AddConfirmationCallback(func(swapId string, txHex string, err error) error)
	AddCsvCallback(func(swapId string) error)
	GetBlockHeight() (uint32, error)
	StartWatchingTxs() error
}

So far, peerswap has used bitcoind/elementsd, but lwk uses the electrum client on which lwk depends.

AddWaitForConfirmationTx(swapId, txId string, vout, startingHeight uint32, scriptpubkey []byte)

Wait for a specific tx to be confirmed with a specific block height.
This function uses the electrum client blockchain.scriptthash.get_history.

AddWaitForCsvTx(swapId, txId string, vout uint32, startingHeight uint32, scriptpubkey []byte)

Wait for a specific tx to reach the csv limit at a specific block height.
This function uses the electrum client blockchain.scriptthash.get_history.

GetBlockHeight() (uint32, error)

Function to retrieve block height.
Use blockchain.headers.subscribe of electrum client.

StartWatchingTxs() error

Function to start tx watcher.
Periodically calls blockchain.scripthash.get_history of electrum client and executes callback when the condition is met.

@YusukeShimizu
YusukeShimizu force-pushed the lwk-swap branch 8 times, most recently from 8603558 to 37f5bcd Compare March 29, 2024 07:51
remove blockwatcher.go and associated block height functions
The blockwatcher.go file and its associated functions for
tracking block height changes have been removed.

block height tracking is no longer necessary and has been replaced
by a different mechanism.
@YusukeShimizu
YusukeShimizu force-pushed the lwk-swap branch 3 times, most recently from 02832df to e7513c6 Compare May 1, 2024 00:47
`CreateFundedTransaction` and `FinalizeFundedTransaction`
have merged interfaces, CreateAndBroadcastTransaction.
This is because there was originally no reason to separate them,
and because lwk uses the psbt format,
transacrion conversion needs to be performed.

The liquid wallet interface should not have a
unique liquid wallet-dependent definition.
However, there were some that depended on gelements,
 so they were separated out.
lwkclient is a library for interacting directly with
lwk server via json rpc.
LWKRpcWallet acts as an onchain wallet for peerswap
It uses lwk and electrs.

- Implement API structure with request handling,
including retry logic and response body draining.
- Provide configuration options for HTTP client with retry logic
- Utilize JSON-RPC 2.0 for request and response handling.
- Ensure proper error handling and logging.

- Create lwkclient with methods for address generation,
sending transactions, signing, broadcasting,
balance querying, and wallet details retrieval.

- Implement LWKRpcWallet with necessary wallet operations
- Ensure wallet setup and transaction creation/broadcasting
- Add utility functions for balance retrieval and fee estimation.
tx watcher is a function that monitors onchain status
and notifies opening tx and closing tx.

Introduce ElectrumRPC interface and electrumTxWatcher
for Electrum-based transaction watching.

Also, add generated mock for electrumRPC interface.
Mock generation is performed by go.uber.org/mock/mockgen.
Input can be in toml or ini format,
but each is managed as the same config.

To make it loosely coupled, used the builder pattern to set item.
I also add validation of the config.
The config file cannot be modified from the outside.
@YusukeShimizu
YusukeShimizu force-pushed the lwk-swap branch 2 times, most recently from 48f67fd to e7769ed Compare May 2, 2024 06:08
Comment thread packages.nix Outdated
Comment on lines +19 to +31
# lwk: init at 0.3.0 #292522
# https://github.com/NixOS/nixpkgs/pull/292522/commits/2b3750792b2e4b52f472b6e6d88a6b02b6536c43
rev2 = "2b3750792b2e4b52f472b6e6d88a6b02b6536c43";
nixpkgs2 = fetchNixpkgs rev2;
pkgs2 = import nixpkgs2 {};
# blockstream-electrs: init at 0.4.1 #299761
# https://github.com/NixOS/nixpkgs/pull/299761/commits/680d27ad847801af781e0a99e4b87ed73965c69a
rev3 = "680d27ad847801af781e0a99e4b87ed73965c69a";
nixpkgs3 = fetchNixpkgs rev3;
pkgs3 = import nixpkgs3 {};
blockstream-electrs = pkgs3.blockstream-electrs.overrideAttrs (oldAttrs: {
cargoBuildFlags = [ "--features liquid" "--bin electrs" ];
});

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There are also nix flakes for lwk and blockstream-electrs, I am curious to know if it was unknown or if it's preferred to avoid flakes

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for confirming this.
I know that flake exists and I'm not trying to avoid installing it.

I don't know enough about nix but would it be better to add binLiquid to the package and use it for peerswap devShell?
I created draft PR of this.

I also seem to get build errors.
I think it should be fixed.

nix run .#blockstream-electrs-liquid -- --network liquid
error: builder for '/nix/store/nkkv9v3r310p5gp09zv3hmn29y63mia3-electrs-deps-0.4.1.drv' failed with exit code 101;
       last 25 log lines:
       >     Checking futures-channel v0.3.30
       >     Checking which v4.4.2
       >    Compiling bitcoind v0.34.1
       >     Checking rand v0.4.6
       >     Checking rustc-demangle v0.1.23
       >     Checking iana-time-zone v0.1.60
       >     Checking unicode-width v0.1.11
       >     Checking tower-service v0.3.2
       >     Checking winapi v0.2.8
       >     Checking option-ext v0.2.0
       >    Compiling bitcoin_hashes v0.10.0
       >     Checking base64-compat v1.0.0
       >     Checking dirs-sys v0.4.1
       >     Checking hyper v0.14.28
       >     Checking bitcoincore-rpc-json v0.18.0
       >    Compiling elementsd v0.9.1
       > error[E0425]: cannot find function `download_filename` in this scope
       >   --> /nix/store/n1a9vx4rppg99v909c7hw2jc5d1yj7f2-vendor-cargo-deps/c19b7c6f923b580ac259164a89f2577984ad5ab09ee9d583b888f934adbbe8d0/elementsd-0.9.1/build.rs:59:33
       >    |
       > 59 |         let download_filename = download_filename();
       >    |                                 ^^^^^^^^^^^^^^^^^ not found in this scope
       >
       > For more information about this error, try `rustc --explain E0425`.
       > error: could not compile `elementsd` (build script) due to previous error
       > warning: build failed, waiting for other jobs to finish...
       For full logs, run 'nix-store -l /nix/store/nkkv9v3r310p5gp09zv3hmn29y63mia3-electrs-deps-0.4.1.drv'.
error: 1 dependencies of derivation '/nix/store/qpdjg9rmj3b9w33l50gmg4jdl8671738-electrs-0.4.1.drv' failed to build

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Which commit are you using?

current new-index branch seems fine to me

$ git log | head -n 1
commit efc1fec8b0f96b5663d7257a0c2cffd8ef143219
$ nix run .#blockstream-electrs-liquid -- --network liquid
Config { log: StdErrLog { verbosity: Error, quiet: false, show_level: true, timestamp: Off, modules: [], writer: "stderr", color_choice: Auto, show_module_names: false }, network_type: Liquid, db_path: "./db/liquid", daemon_dir: "/home/casatta/.bitcoin/liquidv1", blocks_dir: "/home/casatta/.bitcoin/liquidv1/blocks", daemon_rpc_addr: 127.0.0.1:7041, cookie: None, electrum_rpc_addr: 127.0.0.1:51000, http_addr: 127.0.0.1:3000, http_socket_file: None, monitoring_addr: 127.0.0.1:34224, jsonrpc_import: false, light_mode: false, address_search: false, index_unspendables: false, cors: None, precache_scripts: None, utxos_limit: 500, electrum_txs_limit: 500, electrum_banner: "Welcome to electrs-esplora 0.4.1", electrum_rpc_logging: None, parent_network: Bitcoin, asset_db_path: None }

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm using the same commit.
There seems to be an error in my environment.

$ git log | head -n 1
commit efc1fec8b0f96b5663d7257a0c2cffd8ef143219

$ nix run .#blockstream-electrs-liquid -- --network liquid
error: builder for '/nix/store/nkkv9v3r310p5gp09zv3hmn29y63mia3-electrs-deps-0.4.1.drv' failed with exit code 101;
       last 25 log lines:
       >     Checking rand v0.4.6
       >     Checking tower-service v0.3.2
       >     Checking option-ext v0.2.0
       >     Checking winapi v0.2.8
       >     Checking rustc-demangle v0.1.23
       >     Checking unicode-width v0.1.11
       >    Compiling bitcoin_hashes v0.10.0
       >     Checking iana-time-zone v0.1.60
       >     Checking bitcoincore-rpc-json v0.18.0
       >     Checking base64-compat v1.0.0
       >     Checking chrono v0.4.34
       >     Checking textwrap v0.11.0
       >     Checking rand v0.3.23
       >     Checking hyper v0.14.28
       >     Checking dirs-sys v0.4.1
       >    Compiling elementsd v0.9.1
       > error[E0425]: cannot find function `download_filename` in this scope
       >   --> /nix/store/n1a9vx4rppg99v909c7hw2jc5d1yj7f2-vendor-cargo-deps/c19b7c6f923b580ac259164a89f2577984ad5ab09ee9d583b888f934adbbe8d0/elementsd-0.9.1/build.rs:59:33
       >    |
       > 59 |         let download_filename = download_filename();
       >    |                                 ^^^^^^^^^^^^^^^^^ not found in this scope
       >
       > For more information about this error, try `rustc --explain E0425`.
       > error: could not compile `elementsd` (build script) due to previous error
       > warning: build failed, waiting for other jobs to finish...
       For full logs, run 'nix log /nix/store/nkkv9v3r310p5gp09zv3hmn29y63mia3-electrs-deps-0.4.1.drv'.
error: 1 dependencies of derivation '/nix/store/qpdjg9rmj3b9w33l50gmg4jdl8671738-electrs-0.4.1.drv' failed to build

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

can you try a nix flake update before nix run I am thinking to update the flake.lock anyway...

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmmm, doesn't seem to solve the problem.

$ nix flake update
warning: updating lock file '/workspaces/electrs/flake.lock':
• Updated input 'crane':
    'github:ipetkov/crane/a329cd00398379c62e76fc3b8d4ec2934260d636?narHash=sha256-iZDHWTqQj6z6ccqTSEOPOxQ8KMFAemInUObN2R9vHSs%3D' (2024-03-28)
  → 'github:ipetkov/crane/442a7a6152f49b907e73206dc8e1f46a61e8e873?narHash=sha256-uXNW6bapWFfkYIkK1EagydSrFMqycOYEDSq75GmUpjk%3D' (2024-05-04)
• Updated input 'nixpkgs':
    'github:NixOS/nixpkgs/2726f127c15a4cc9810843b96cad73c7eb39e443?narHash=sha256-UKcYiHWHQynzj6CN/vTcix4yd1eCu1uFdsuarupdCQQ%3D' (2024-03-27)
  → 'github:NixOS/nixpkgs/b211b392b8486ee79df6cdfb1157ad2133427a29?narHash=sha256-CLU5Tsg24Ke4%2B7sH8azHWXKd0CFd4mhLWfhYgUiDBpQ%3D' (2024-05-07)
• Updated input 'rust-overlay':
    'github:oxalica/rust-overlay/aa858717377db2ed8ffd2d44147d907baee656e5?narHash=sha256-oD4OJ3TRmVrbAuKZWxElRCyCagNCDuhfw2exBmNOy48%3D' (2024-03-28)
  → 'github:oxalica/rust-overlay/a8bfc2569a1965c0da8711d289d973f0011b441a?narHash=sha256-oujsCgNiQnZoQntNkkNkA7BhCmUvf9FLWj%2B2oGT2Jvc%3D' (2024-05-08)
warning: Git tree '/workspaces/electrs' is dirty
$ nix run .#blockstream-electrs-liquid -- --network liquid
warning: Git tree '/workspaces/electrs' is dirty
error: builder for '/nix/store/rcd2hcxdnb6v23c7mjjm33wqjbasdrvr-electrs-deps-0.4.1.drv' failed with exit code 101;
       last 25 log lines:
       >    Compiling bitcoin_hashes v0.12.0
       >     Checking object v0.32.2
       >     Checking futures-channel v0.3.30
       >     Checking which v4.4.2
       >    Compiling bitcoind v0.34.1
       >     Checking rand v0.4.6
       >     Checking iana-time-zone v0.1.60
       >     Checking tower-service v0.3.2
       >     Checking rustc-demangle v0.1.23
       >     Checking unicode-width v0.1.11
       >    Compiling bitcoin_hashes v0.10.0
       >     Checking bitcoincore-rpc-json v0.18.0
       >     Checking option-ext v0.2.0
       >     Checking winapi v0.2.8
       >    Compiling elementsd v0.9.1
       > error[E0425]: cannot find function `download_filename` in this scope
       >   --> /nix/store/cjjfa06qzk9wahmbqjh7kn86bsmaq3dv-vendor-cargo-deps/c19b7c6f923b580ac259164a89f2577984ad5ab09ee9d583b888f934adbbe8d0/elementsd-0.9.1/build.rs:59:33
       >    |
       > 59 |         let download_filename = download_filename();
       >    |                                 ^^^^^^^^^^^^^^^^^ not found in this scope
       >
       > For more information about this error, try `rustc --explain E0425`.
       >     Checking dirs-sys v0.4.1
       > error: could not compile `elementsd` (build script) due to previous error
       > warning: build failed, waiting for other jobs to finish...
       For full logs, run 'nix log /nix/store/rcd2hcxdnb6v23c7mjjm33wqjbasdrvr-electrs-deps-0.4.1.drv'.
error: 1 dependencies of derivation '/nix/store/z7wa0ixizb5xq32dfs8s0fv23yds4lcl-electrs-0.4.1.drv' failed to build

The integration test for LWK is added to ensure
that the swap functionality works as expected
with the LWK and electrs support.

The setup functions are implemented to create the necessary test
environment, including lwk, Bitcoin and Liquid nodes,
 as well as two lightning nodes with the PeerSwap.
This setup is crucial for testing the swap-in process
in an environment that closely mimics production.

also, added Electrs and LWK structs for testing framework.
- Implement `Electrs` struct to manage electrs daemon processes
- Implement `LWK` struct to manage LWK daemon processes
- Provide constructors for both structs to
initialize with dynamic ports and configurations
- Include methods to run the processes and connect
@YusukeShimizu YusukeShimizu changed the title wip: make lwk available make lwk available May 6, 2024
@YusukeShimizu
YusukeShimizu marked this pull request as ready for review May 6, 2024 01:05
@grubles

grubles commented May 8, 2024

Copy link
Copy Markdown
Contributor

CLN as swap-out sender seems to be unable to get the starting block height from LWK?

Using CLN 24.02.2 and LWK 0.3.0

2eb4834f573c060d9200ce77544a29b48a0aa5923 got msgtype: a45d for swap: efa2c9c38ea24acff600af12d61677f50679b0e2d137fcd037c760411eaa4cfc
2024-05-08T19:09:05.555Z DEBUG   plugin-peerswap: [FSM] event:id: efa2c9c38ea24acff600af12d61677f50679b0e2d137fcd037c760411eaa4cfc, Event_OnTxOpenedMessage on State_SwapOutSender_AwaitTxBroadcastedMessage
2024-05-08T19:09:05.584Z INFO    plugin-peerswap: [FSM] Action failure could not get starting block height of the swap.
2024-05-08T19:09:05.585Z DEBUG   plugin-peerswap: [FSM] event:id: efa2c9c38ea24acff600af12d61677f50679b0e2d137fcd037c760411eaa4cfc, Event_ActionFailed on State_SwapOutSender_AwaitTxConfirmation
2024-05-08T19:09:05.591Z DEBUG   plugin-peerswap: [FSM] event:id: efa2c9c38ea24acff600af12d61677f50679b0e2d137fcd037c760411eaa4cfc, Event_ActionSucceeded on State_SwapOutSender_SendPrivkey
2024-05-08T19:09:05.592Z DEBUG   035ca2fe4793a5e789ce846062eb4834f573c060d9200ce77544a29b48a0aa5923-connectd: peer_out INVALID 42081
2024-05-08T19:09:05.599Z DEBUG   plugin-peerswap: [FSM] event:id: efa2c9c38ea24acff600af12d61677f50679b0e2d137fcd037c760411eaa4cfc, Event_ActionSucceeded on State_SwapOutSender_SendCoopClose
2024-05-08T19:09:05.600Z INFO    plugin-peerswap: [Swap:efa2c9c38ea24acff600af12d61677f50679b0e2d137fcd037c760411eaa4cfc] Swap claimed cooperatively

@YusukeShimizu
YusukeShimizu force-pushed the lwk-swap branch 4 times, most recently from 44c7d05 to a448d46 Compare May 9, 2024 07:39
@grubles

grubles commented Jun 12, 2024

Copy link
Copy Markdown
Contributor

CLN PeerSwap still allows me to start a swap-out with the LWK backend shut down. To reproduce, shut down the running LWK server while CLN is running before attempting a swap-out. Then try the swap-out.

The swap will eventually become stuck at this point:

      {
         "id": "20a0dc7de9571334652f9ac551b126bf08099865a76abbc7f732d67cbfecdd8e",
         "created_at": 1718204649,
         "asset": "lbtc",
         "type": "swap-out",
         "role": "sender",
         "state": "State_SwapOutSender_ClaimSwap",
         "initiator_node_id": "036e680823a129ac9a2eeb8c43514a5b6cb09ae28e3e698a0e34aaa8865d6cc344",
         "peer_node_id": "035ca2fe4793a5e789ce846062eb4834f573c060d9200ce77544a29b48a0aa5923",
         "amount": 9008040,
         "channel_id": "194668x21x0",
         "opening_tx_id": "3212fa7d8ce763161a7c701e5af84112607b13690e6879ea08c0f9505c71f9a2",
         "lnd_chan_id": 214039729557274624
      }

Even when LWK is restarted, CLN PeerSwap isn't able to recover after about 30 seconds have passed:

Here peerswap stops retrying the LWK backend after ~30 seconds:

2024-06-12T17:28:56.515Z INFO    plugin-peerswap: Error claiming tx with preimage failed to call api request: POST http://localhost:32111 giving up after 2 attempt(s): Post \"http://localhost:32111\": dial tcp [::1]:32111: connect: connection refused


Here the LWK backend is restarted but peerswap does nothing:

2024-06-12T17:29:02.306Z DEBUG   plugin-peerswap: New block received. block height:1433751
2024-06-12T17:30:02.804Z DEBUG   plugin-peerswap: New block received. block height:1433752
2024-06-12T17:31:02.663Z DEBUG   plugin-peerswap: New block received. block height:1433753

@YusukeShimizu
YusukeShimizu force-pushed the lwk-swap branch 2 times, most recently from a3d1b07 to 692383e Compare June 12, 2024 22:27
add a plugin hook in the case of core lightning and
an interceptor in the case of lnd, and pre-install
a dead/alive monitor for each daemon.
This way, it prevents many automated clients from attacking
the server at the same time.
For example, 37, 41, 43, 47, 53, 59, 61, 67, 71, 73, 79,
83, 89 and 97 are good numbers.
@YusukeShimizu

YusukeShimizu commented Jun 12, 2024

Copy link
Copy Markdown
Contributor Author

I have confirmed that the following in my environment: aa9550b

bin/clncli peerswap-swap-out $CLNSHORTCHANID 1000000 lbtc
{
   "message": "liquid_unavailable",
   "code": -1
}

The log details are as follows:

peerswap-playground-cln1-1       | 2024-06-12T23:30:14.737Z DEBUG   lightningd: Calling rpc_command hook of plugin peerswap
peerswap-playground-cln1-1       | 2024-06-12T23:30:14.742Z INFO    plugin-peerswap: trying to send command peerswap-swap-out, but failed to connect: Post \"http://elementsd:8332/wallet/peerswap\": dial tcp: lookup elementsd on 127.0.0.11:53: no such host
peerswap-playground-cln1-1       | 2024-06-12T23:30:14.742Z DEBUG   lightningd: Plugin peerswap returned from rpc_command hook call
  • LND
./bin/pscli peerswap1 listswaps
2024/06/12 23:41:13 rpc error: code = Unknown desc = liquid backend not reachable: lwk connection failed: failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host

Even when LWK is restarted, CLN PeerSwap isn’t able to recover after about 30 seconds have passed:

Recovery of swaps occurs only when the plugin is restarted.
This may also be useful for other backend recovery scenarios, but identifying the impact and formulating an adequate strategy will require further consideration.

For reconnection to electrs, I have set a prime number interval (37 seconds).
1d98fe2

@grubles

grubles commented Jun 13, 2024

Copy link
Copy Markdown
Contributor

{
"message": "liquid_unavailable",
"code": -1
}

Peerswap now doesn't try a swap-out if LWK server is shutdown, but I'm not seeing that specific error message:

$ lightning-cli --signet peerswap-swap-out 194668x21x0 9008040 lbtc
lightning-cli: Reading enable response: No such file or directory

Strangely, when I go to shutdown CLN v24.05, the recover plugin crashes now?:

2024-06-13T16:46:28.894Z INFO    plugin-peerswap: trying to send command listpeerchannels, but failed to connect: lwk connection failed: failed to call api request: POST http://localhost:32111 giving up after 2 attempt(s): Post \"http://localhost:32111\": dial tcp [::1]:32111: connect: connection refused
2024-06-13T16:46:29.800Z INFO    plugin-recover: Killing plugin: exited during normal operation
2024-06-13T16:46:29.802Z **BROKEN** plugin-recover: Plugin marked as important, shutting down lightningd!
$ lightning-cli --signet stop
lightning-cli: Reading enable response: No such file or directory
[user@fedora peerswap]$ recover: FATAL SIGNAL 11 (version v24.05)
0x428f0f send_backtrace
        common/daemon.c:33
0x428fa3 crashdump
        common/daemon.c:75
0xffffa6cc47ef ???
        ???:0
0x4142e4 jsonrpc_stream_start
        plugins/libplugin.c:382
0x4144f3 command_done_raw
        plugins/libplugin.c:530
0x415e6f forward_error
        plugins/libplugin.c:584
0x418dfb handle_rpc_reply
        plugins/libplugin.c:982
0x41905f rpc_read_response_one
        plugins/libplugin.c:1183
0x4190ff rpc_conn_read_response
        plugins/libplugin.c:1207
0x4bc51f next_plan
        ccan/ccan/io/io.c:60
0x4bcaeb do_plan
        ccan/ccan/io/io.c:408
0x4bcbab io_ready
        ccan/ccan/io/io.c:418
0x4bea7b io_loop
        ccan/ccan/io/poll.c:455
0x4194b7 plugin_main
        plugins/libplugin.c:2209
0x414147 main
        plugins/recover.c:291
0xffffa67e09db ???
        ???:0
0xffffa67e0aaf ???
        ???:0
0x4107ef ???
        ???:0
0xffffffffffffffff ???
        ???:0

@YusukeShimizu

YusukeShimizu commented Jun 13, 2024

Copy link
Copy Markdown
Contributor Author

This is not expected behavior.
I will investigate.

This change causes the liquid daemon to be monitored
for dead or alive at the start of the swapout execution.
Previously, at the start of a swapout,
it would succeed even if the liquid daemon was not running,
If a subsequent process required the liquid daemon,
 an error would occur.

In addition, cross-checking by interceptors and hooks
 has been discontinued.
This is because hooks by glightning are unstable and currently only
 swapout needs to be monitored for life and death.
@YusukeShimizu

Copy link
Copy Markdown
Contributor Author

Could not reproduce.
But, in my environment, I have confirmed that sometimes the following is displayed

lightning-cli: Reading enable response: Bad address

It seems to be a bug related to the glightning plugin hook, but the cause has not been identified.
The hook mechanism is unstable, so changed to check at the start of swap out

  • cln
/clncli peerswap-swap-out $CLNSHORTCHANID 1000000 lbtc
{
   "code": -1,
   "message": "liquid wallet not reachable: Post \"http://elementsd:8332/wallet/peerswap\": dial tcp: lookup elementsd on 127.0.0.11:53: no such host"
}
  • lnd
pscli peerswap1 swapout --channel_id $CHANID --sat_amt 1000000 --asset lbtc
2024/06/16 02:02:06 rpc error: code = Unknown desc = liquid backend not reachable: lwk connection failed: failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host

@YusukeShimizu
YusukeShimizu force-pushed the lwk-swap branch 3 times, most recently from fd00a84 to 96c4f37 Compare June 18, 2024 03:04
add tests for backend down scenarios in LWK.
Add tests to handle scenarios where the backend services
(LWK and Electrs) are down during swaps.
@YusukeShimizu

YusukeShimizu commented Jun 24, 2024

Copy link
Copy Markdown
Contributor Author

Summarise the problems that have occurred when the backend is down and the measures taken to deal with them.
For verification, I use https://github.com/YusukeShimizu/peerswap-playground/tree/master/lnd_lwk.

hung in State_SwapOutSender_ClaimSwap.

Transition from State_SwapOutSender_ClaimSwap is not possible if lwk is stopped
This is because the CreatePreimageSpendingTransaction fails, Event_OnRetry is set and retries are repeated.

The Event_OnRetry is designed to execute 20 retries and stop the process if it still fails.
In the meantime, if the lwk is not restarted, the process will be stopped.

To rescue the hang, peerswap itself needs to be restarted with lwk restarted and the RECOVER process carried out.

solution

Allow retries with backoff during Event_OnRetry and perform a coop close if it eventually fails.

procedure

./bin/pscli peerswap1 swapout --channel_id $CHANID --sat_amt 1000000 --asset lbtc
{
  "swap":  {
    "id":  "4ef286a1b67b11b6256fc4f33a6f0b2a0dab80bbf97383f7b28eabf425a655af",
    "created_at":  "1719187011",
    "asset":  "lbtc",
    "type":  "swap-out",
    "role":  "sender",
    "state":  "State_SwapOutSender_AwaitTxConfirmation",
    "initiator_node_id":  "03a2398d621172e94b296853b67d51974dba7d3eb25f49408dd76fac03055fa2c6",
    "peer_node_id":  "0372a196c83b1ec8406cf14e9165fabe418f49d25f511366b15bc01bce3659dd08",
    "amount":  "1000000",
    "channel_id":  "116:1:1",
    "opening_tx_id":  "dca5b4f8cf4aaf989f15508557db7d2274d83273a854695e3f77ff4b7ca613b2",
    "claim_tx_id":  "",
    "cancel_message":  "",
    "lnd_chan_id":  "127543348887553"
  }
}

In this state, lwk down and generate the block.

./bin/elements-cli -rpcwallet=peerswap1 -generate 3
{
  "address": "el1qqgur95kqj5h8r25dc9rs7vj63xzdzxjr3fz25ph290s7m0equygstuh6ukh590ev2ggfw7r0ywpkqq29vx7djuzksgjy8x0wp",
  "blocks": [
    "3d6a07837fe3e35fc5d35bf46baea8d9275e2b94f1d11462d19cfefb7ac0dd95",
    "8edd881f0ff22a4efc2b339e372f070932e49589d44c5b214fc300f38431c5e6",
    "2212796f8e922d25541556e4720a7575a5266a6efc1935052a47ecc552e5e0b4"
  ]
}

The state transitions as follows
State_SwapOutSender_AwaitTxConfirmation->State_SwapOutSender_ValidateTxAndPayClaimInvoice->State_SwapOutSender_ClaimSwap

./bin/pscli peerswap1 listswaps
{
  "swaps":  [
    {
      "id":  "4ef286a1b67b11b6256fc4f33a6f0b2a0dab80bbf97383f7b28eabf425a655af",
      "created_at":  "1719187011",
      "asset":  "lbtc",
      "type":  "swap-out",
      "role":  "sender",
      "state":  "State_SwapOutSender_ClaimSwap",
      "initiator_node_id":  "03a2398d621172e94b296853b67d51974dba7d3eb25f49408dd76fac03055fa2c6",
      "peer_node_id":  "0372a196c83b1ec8406cf14e9165fabe418f49d25f511366b15bc01bce3659dd08",
      "amount":  "1000000",
      "channel_id":  "116:1:1",
      "opening_tx_id":  "dca5b4f8cf4aaf989f15508557db7d2274d83273a854695e3f77ff4b7ca613b2",
      "claim_tx_id":  "",
      "cancel_message":  "",
      "lnd_chan_id":  "127543348887553"
    }
  ]
}

In this state, restarting the lwk causes a transition from State_SwapOutSender_ClaimSwap to State_ClaimedPreimage.

./bin/pscli peerswap1 listswaps
{
  "swaps":  [
    {
      "id":  "4ef286a1b67b11b6256fc4f33a6f0b2a0dab80bbf97383f7b28eabf425a655af",
      "created_at":  "1719187011",
      "asset":  "lbtc",
      "type":  "swap-out",
      "role":  "sender",
      "state":  "State_ClaimedPreimage",
      "initiator_node_id":  "03a2398d621172e94b296853b67d51974dba7d3eb25f49408dd76fac03055fa2c6",
      "peer_node_id":  "0372a196c83b1ec8406cf14e9165fabe418f49d25f511366b15bc01bce3659dd08",
      "amount":  "1000000",
      "channel_id":  "116:1:1",
      "opening_tx_id":  "dca5b4f8cf4aaf989f15508557db7d2274d83273a854695e3f77ff4b7ca613b2",
      "claim_tx_id":  "06e677aa5eab366e4321b98c8589003fcf9f68b658f6089c12e0131e9e89335a",
      "cancel_message":  "",
      "lnd_chan_id":  "127543348887553"
    }
  ]
}

hung in State_SwapOutSender_AwaitTxConfirmation

Transition from State_SwapOutSender_AwaitTxConfirmation is not possible in a situation where block subscribe is not possible.

When the block's subscribe is resumed, if the safety limit is exceeded, the private key is sent and a transition is made to State_ClaimedCoop, but the same transition is made if the csv limit is exceeded.
If the responder performs csv close, it also becomes State_ClaimedCoop, but in the case of csv close, it should become State_ClaimedCSV and there is no mechanism to detect this state.

solution

It may be possible to get onchain information to determine if the csv is displayed correctly, but this needs to be considered.
Alternatively, if the csv limit is exceeded, it may be possible to exit as State_ClaimedCSV

procedure

./bin/pscli peerswap1 swapout --channel_id $CHANID --sat_amt 1000000 --asset lbtc
{
  "swap":  {
    "id":  "b28c312d3deeedaa576820ef0f81a1e0b31b7e22dc48fc88247b5dee470621b1",
    "created_at":  "1719189360",
    "asset":  "lbtc",
    "type":  "swap-out",
    "role":  "sender",
    "state":  "State_SwapOutSender_AwaitTxConfirmation",
    "initiator_node_id":  "03d627f50febcb572d0c7c20bc1a3d74bbb0fb38bf2923e36693f92cf1530b5b17",
    "peer_node_id":  "02946f5695612919b1ef1a86a767699800e09389a2447c023f9eb0e0613b0cf1c3",
    "amount":  "1000000",
    "channel_id":  "116:1:1",
    "opening_tx_id":  "3c4095ebaea17b2ee9972094a1897841adf275cbad47fcb93ce2dc85c095dceb",
    "claim_tx_id":  "",
    "cancel_message":  "",
    "lnd_chan_id":  "127543348887553"
  }
}

In this state, lwk and electrs are turned down and the block is generated.
Generate as much as the safetyLimit is exceeded.

./bin/elements-cli -rpcwallet=peerswap1 -generate 100

Restart peerswap,lwk,electrs.
Transition to State_SwapOutSender_AwaitTxConfirmation -> State_SwapOutSender_SendPrivkey -> State_ClaimedCoop.

./bin/pscli peerswap1 listswaps
{
  "swaps":  [
    {
      "id":  "b28c312d3deeedaa576820ef0f81a1e0b31b7e22dc48fc88247b5dee470621b1",
      "created_at":  "1719189360",
      "asset":  "lbtc",
      "type":  "swap-out",
      "role":  "sender",
      "state":  "State_ClaimedCoop",
      "initiator_node_id":  "03d627f50febcb572d0c7c20bc1a3d74bbb0fb38bf2923e36693f92cf1530b5b17",
      "peer_node_id":  "02946f5695612919b1ef1a86a767699800e09389a2447c023f9eb0e0613b0cf1c3",
      "amount":  "1000000",
      "channel_id":  "116:1:1",
      "opening_tx_id":  "3c4095ebaea17b2ee9972094a1897841adf275cbad47fcb93ce2dc85c095dceb",
      "claim_tx_id":  "",
      "cancel_message":  "exceeded safe swap range.",
      "lnd_chan_id":  "127543348887553"
    }
  ]
}

Remarks

To State_SwapOutSender_AwaitTxConfirmation, even if swapout is enforced with lwk down, the latest commit cannot transition because validation has been added.

/clncli peerswap-swap-out $CLNSHORTCHANID 1000000 lbtc
pscli peerswap1 swapout --channel_id $CHANID --sat_amt 1000000 --asset lbtc
2024/06/16 02:02:06 rpc error: code = Unknown desc = liquid backend not reachable: lwk connection failed: failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host

@YusukeShimizu

YusukeShimizu commented Jun 26, 2024

Copy link
Copy Markdown
Contributor Author

After the start of swapout;
if lwk is assumed to be stopped After about 10 minutes of back-off, the priv key is sent and the coop closed.

log
2024-06-26 09:22:00 2024/06/26 00:22:00 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnSwapOutStarted on 
2024-06-26 09:22:00 2024/06/26 00:22:00 [INFO] [Swap:87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef] Start new swap-out: peer: 03457dabca72cdf096e7f27cd78673796306c21fc684d25f0ae714a87009ca9750 chanId: 116:1:1 initiator: 03b70410f1fc0b37fea10a92df8179b66362f8ac9cbb3058e8b69d897a5311caf0 amount 1000000
2024-06-26 09:22:00 2024/06/26 00:22:00 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_ActionSucceeded on State_SwapOutSender_CreateSwap
2024-06-26 09:22:00 2024/06/26 00:22:00 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_ActionSucceeded on State_SwapOutSender_SendRequest
2024-06-26 09:22:00 2024/06/26 00:22:00 [DEBUG] [Messenger] From: 03457dabca72cdf096e7f27cd78673796306c21fc684d25f0ae714a87009ca9750 got msgtype: a45b for swap: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef
2024-06-26 09:22:00 2024/06/26 00:22:00 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnFeeInvoiceReceived on State_SwapOutSender_AwaitAgreement
2024-06-26 09:22:00 2024/06/26 00:22:00 [DEBUG] Using minimum fee rate of 0.1 sat/kw
2024-06-26 09:22:00 2024/06/26 00:22:00 [DEBUG] PayInvoiceViaChannel: payment still in flight
2024-06-26 09:22:01 2024/06/26 00:22:01 [DEBUG] PayInvoiceViaChannel: payment still in flight
2024-06-26 09:22:02 2024/06/26 00:22:02 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_ActionSucceeded on State_SwapOutSender_PayFeeInvoice
2024-06-26 09:22:02 2024/06/26 00:22:02 [INFO] [Swap:87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef] Paid Feeinvoice of 300 sats
2024-06-26 09:22:02 2024/06/26 00:22:02 [DEBUG] [Messenger] From: 03457dabca72cdf096e7f27cd78673796306c21fc684d25f0ae714a87009ca9750 got msgtype: a45d for swap: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef
2024-06-26 09:22:02 2024/06/26 00:22:02 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnTxOpenedMessage on State_SwapOutSender_AwaitTxBroadcastedMessage
2024-06-26 09:22:02 2024/06/26 00:22:02 [DEBUG] Await confirmation for tx with id: bc68c580af45fad42f77d5451d96d64449a698dafce07c309e5fafc6fc2eb97b on swap 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef
2024-06-26 09:22:10 2024/06/26 00:22:10 [DEBUG] [Messenger] From: 03457dabca72cdf096e7f27cd78673796306c21fc684d25f0ae714a87009ca9750 got same message for swap: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef
2024-06-26 09:22:10 2024/06/26 00:22:10 [INFO] [MsgListener]: Handler failed: Message already exists
2024-06-26 09:22:15 2024/06/26 00:22:15 [DEBUG] New block received. block height:18
2024-06-26 09:22:15 2024/06/26 00:22:15 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnTxConfirmed on State_SwapOutSender_AwaitTxConfirmation
2024-06-26 09:22:20 2024/06/26 00:22:20 [DEBUG] [Messenger] From: 03457dabca72cdf096e7f27cd78673796306c21fc684d25f0ae714a87009ca9750 got same message for swap: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef
2024-06-26 09:22:25 2024/06/26 00:22:25 [DEBUG] PayInvoiceViaChannel: payment still in flight
2024-06-26 09:22:26 2024/06/26 00:22:26 [DEBUG] PayInvoiceViaChannel: payment still in flight
2024-06-26 09:22:27 2024/06/26 00:22:27 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_ActionSucceeded on State_SwapOutSender_ValidateTxAndPayClaimInvoice
2024-06-26 09:22:29 2024/06/26 00:22:29 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:22:30 2024/06/26 00:22:30 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:22:31 2024/06/26 00:22:31 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:22:32 2024/06/26 00:22:32 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:22:33 2024/06/26 00:22:33 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:22:36 2024/06/26 00:22:36 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:22:38 2024/06/26 00:22:38 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:22:48 2024/06/26 00:22:48 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:22:49 2024/06/26 00:22:49 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:23:08 2024/06/26 00:23:08 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:23:10 2024/06/26 00:23:10 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:23:11 2024/06/26 00:23:11 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:23:13 2024/06/26 00:23:13 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:23:24 2024/06/26 00:23:24 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:23:26 2024/06/26 00:23:26 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:23:27 2024/06/26 00:23:27 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:23:29 2024/06/26 00:23:29 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:23:35 2024/06/26 00:23:35 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:23:37 2024/06/26 00:23:37 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:23:55 2024/06/26 00:23:55 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:23:57 2024/06/26 00:23:57 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:24:06 2024/06/26 00:24:06 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:24:07 2024/06/26 00:24:07 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:24:18 2024/06/26 00:24:18 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:24:19 2024/06/26 00:24:19 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:24:27 2024/06/26 00:24:27 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:24:29 2024/06/26 00:24:29 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:24:46 2024/06/26 00:24:46 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:24:47 2024/06/26 00:24:47 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:24:48 2024/06/26 00:24:48 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:24:49 2024/06/26 00:24:49 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:25:05 2024/06/26 00:25:05 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:25:07 2024/06/26 00:25:07 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:25:18 2024/06/26 00:25:18 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:25:19 2024/06/26 00:25:19 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:25:29 2024/06/26 00:25:29 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:25:31 2024/06/26 00:25:31 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:25:47 2024/06/26 00:25:47 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:25:48 2024/06/26 00:25:48 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:25:51 2024/06/26 00:25:51 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnRetry on State_SwapOutSender_ClaimSwap
2024-06-26 09:25:54 2024/06/26 00:25:54 [INFO] Error claiming tx with preimage failed to call api request: POST http://lwk:32113 giving up after 2 attempt(s): Post "http://lwk:32113": dial tcp: lookup lwk: no such host
2024-06-26 09:26:09 2024/06/26 00:26:09 [INFO] [MsgListener]: Handler failed: Message already exists
2024-06-26 09:32:00 2024/06/26 00:32:00 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_OnTimeout on State_SwapOutSender_ClaimSwap
2024-06-26 09:32:00 2024/06/26 00:32:00 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_ActionSucceeded on State_SwapOutSender_SendPrivkey
2024-06-26 09:32:00 2024/06/26 00:32:00 [DEBUG] [FSM] event:id: 87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef, Event_ActionSucceeded on State_SwapOutSender_SendCoopClose
2024-06-26 09:32:00 2024/06/26 00:32:00 [INFO] [Swap:87a67002b3ef6f5a3de545b80df36ea5b5db61d0e1ec1e99e8e12919a368c4ef] Swap claimed cooperatively

Also, confirm that the number of groutine occurrences is normal in the debug run.
This no longer results in blocksubscriber outages.

@grubles

grubles commented Jun 26, 2024

Copy link
Copy Markdown
Contributor

Tested both CLN and LND as swap-out sender. Can confirm the swap now ends up as claimed coop after ~10 minutes with LWK down, instead of getting stuck.

ensure client is properly reinitialized before subscribing to headers
 to prevent potential stale connections.
The Event_OnRetry is designed to execute 20 retries and stop
the process if it still fails.

This patch adds the missing Event_OnTimeout transition to
transit to coop close if the lwk is not restarted.

@nepet nepet left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice work @YusukeShimizu! That was a heavy lift. I really like your interface refinements and the way you seamlessly integrate lwk into the rest of the repo. I wish the rest of the repo would be as clean as the lwk package ^^.

I may have an explanation as to why the liveleyness test using the rpc_command hook resulted in unexpected behaviour, crashing other plugins: The hook will be called on EVERY rpc call globally, regardless the method or the namespace. So if peerswap as a plugin is still active but the connection to gbitcoin or elements is already lost, this results in returning an error on EVERY rpc call made (inter process as well) which may crash other plugins that come after peerswap in the shutdown sequence. A possible fix would have been to only act on methods that are of peerswaps namespace.

I have some minor nits about naming of units - kvB and vB mixups and would suggest to revisit the fee unit conversion unit-test as it seems to be off.

Besides that the PR seemes good to go for me to test it out in the wild.

Comment thread lwk/lwkwallet.go Outdated
Comment thread electrum/block_subscriber.go
Comment thread electrum/block_subscriber.go Outdated
Comment thread lwk/lwkwallet.go Outdated
Comment thread lwk/lwkwallet.go Outdated
Comment thread lwk/lwkwallet.go Outdated
Comment thread lwk/lwkwallet_test.go Outdated
Comment thread clightning/clightning.go Outdated
Comment thread clightning/clightning.go Outdated
Comment thread lwk/electrumtxwatcher.go
The version of lwk has been raised to cli_0.5.1.
Change to use flake to use cli_0.5.1 in nix as well.
Using flake allows you to run nix develop instead of nix-shell.

Just uses the flake on nix shell.
For the nix-env addon users.
Variable and function names have been corrected
to eliminate confusion with fee calculations.
Test cases have also been refactored.
implement SetLabel method to call walletSetTxMemo
for setting transaction memos.
@YusukeShimizu

Copy link
Copy Markdown
Contributor Author

Thank you for your review.
Can you please confirm that I have made the following corrections?

  • Migrated nix to nix flake and update lwk version to use wallet_set_tx_memo. 45fb414
    • flake was needed to update the lwk version, but as it is common to use flake, I think this is a good opportunity to switch.
    • In addition, CI is now also faster, around 6 minutes.
  • Refactor of tx fee calculation 7045055
    • Mainly name fixes and test case fixes.
  • set label 66fead0

@nepet

nepet commented Jul 1, 2024

Copy link
Copy Markdown
Member

Looks good to me!
Ack 66fead0

@grubles

grubles commented Jul 4, 2024

Copy link
Copy Markdown
Contributor

Tested ACK 66fead0

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants