Loop out failed and cost 30,000 sats

[ajohnson651]

trafficstars

I attempted a loop out using RTL (0.12.3), LND (0.15.0), Loop (v0.20.1) after a couple of days it failed with reason

Swap payment failed: payment failed: FAILURE_REASON_NO_ROUTE

It costs the server 30,000 sats. Anyway to see if a loop out will be able to find a route before sending the 30,000 prepayment or is another way to prevent this? The loop out was for 1,000,000 sats

[bitromortac]

Are you sure it was for the same loop-out? In my understanding only a simultaneous prepayment and swap hold-invoice payment unlocks publication of the on-chain HTLC.

Also see this comment: https://github.com/lightninglabs/loop/issues/486#issuecomment-1117231415

[ajohnson651]

Yeah it was the same. Here is the tail end of the log. Earlier it looked like the server thought it was too expensive to sweep (by 1 sat) but it looked like it was still initiated and attempted it the swap again but finally failed.

2022-09-10 21:02:19.191 [INF] LOOP: b0f281 Register 1 conf ntfn for swap script on chain (hh=753244)
2022-09-10 21:02:19.192 [INF] LOOP: b0f281 Checking preimage reveal height 753524 exceeded (height 753546)
2022-09-10 21:02:19.192 [INF] LOOP: b0f281 Max preimage reveal height 753524 exceeded (height 753546)
2022-09-10 21:02:19.192 [INF] LOOP: b0f281 Wait for server pulling off-chain payment(s)
2022-09-10 21:02:19.195 [INF] LOOP: b0f281 Payment (b0f281xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx) try count 1/1 (plugin=None)
2022-09-10 21:02:19.195 [INF] LOOP: b0f281 Server update: SERVER_FAILED_TIMEOUT received, timestamp: 2022-09-10 20:37:55.349043138 -0500 CDT
2022-09-10 21:02:19.200 [INF] LOOP: b0f281 swap subscription: server finished serving updates
2022-09-10 21:02:19.198 [INF] LOOP: b0f281 Payment (341aadxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx) try count 1/1 (plugin=None)
2022-09-10 21:02:19.235 [INF] LOOP: b0f281 Payment 341aadxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx: state=SUCCEEDED
2022-09-10 21:02:19.247 [INF] LOOP: b0f281 Payment b0f281xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx: state=IN_FLIGHT, inflight_htlcs=1, inflight_amt=971442000 mSAT
2022-09-11 22:15:04.646 [INF] LOOP: b0f281 Payment b0f281xxxxxxxxxxxxxxxxxxxxxxxxx: state=IN_FLIGHT, inflight_htlcs=0, inflight_amt=0 mSAT
2022-09-11 22:15:04.676 [INF] LOOP: b0f281 Payment b0f281xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx: state=FAILED
2022-09-11 22:15:04.861 [INF] LOOP: b0f281 Swap payment failed: payment failed: FAILURE_REASON_NO_ROUTE
2022-09-11 22:15:04.861 [INF] LOOP: b0f281 Swap completed: FailTimeout (final cost: server 0.0003 BTC, onchain 0 BTC, offchain 0.00000004 BTC)
2022-09-11 22:15:04.915 [INF] LOOP: b0f281 Loop out swap state: FailTimeout

[bitromortac]

From what I saw in the code is that there should be two hold-invoices for each payment. Only then the HTLC is published onchain and if the server has to claim back the onchain funds, the preprobe payment is settled. You could check listpayments and look for whether you have sent 30000 sats.

It costs the server 30,000 sats.

To my understanding that's not correct, that's the cost you would need to pay the server in case of not reveiling the preimage (by going offline).

[ajohnson651]

The 30,000 prepayment succeeded. In the log i posted it's the payment hash starting with 341aad you can also see in the final cost: server 0.0003 btc

[saubyk]

Hi @ajohnson651 do you see a completed payment for 30k sats on your payments page in RTL?

[ajohnson651]

Yes I do. the 30000 payment went through right away but then i think my server must have had an issue sweeping the on-chain from what i see in the log but i still saw it was initiated and it looked like it was trying the payment again on 9/11 before failing.

The loop seemed stuck so I tried a reboot sometime on the 10th but other than that my server was on and I believe it had an internet connection the entire time.

Here are some screenshots for what i see in RTL

[bitromortac]

Could you provide complete logs (can be redacted for privacy), ideally starting from line [INF] LOOP: Initiating swap request at height ...? Did your node restart in between? You can also check that the HTLC was published, by looking after the swap address (click View Info).

[ajohnson651]

Here is the loopd log. To me it looks like my server didn't want to pay 1 extra sat so it ended up paying 30,004 instead. I believe the reboot was at 2022-09-10 20:42:12

loopd.log

[bitromortac]

Thank you for providing the logs, that's very helpful! Would you be able to post the output of loop getparams? Have you set any parameters in a user interface for maximal miner fees? In your lnd.conf, do you have set anything for feeurl or bitcoind.estimatemode?

[ajohnson651]

$ loop getparams { "rules": [ ], "fee_ppm": "20000", "sweep_fee_rate_sat_per_vbyte": "0", "max_swap_fee_ppm": "0", "max_routing_fee_ppm": "0", "max_prepay_routing_fee_ppm": "0", "max_prepay_sat": "0", "max_miner_fee_sat": "0", "sweep_conf_target": 100, "failure_backoff_sec": "86400", "autoloop": false, "autoloop_budget_sat": "335544", "autoloop_budget_start_sec": "0", "auto_max_in_flight": "1", "min_swap_amount": "0", "max_swap_amount": "0", "htlc_conf_target": 6 }

I don't have anything set for freeurl or bitcoind.estimatemode in lnd.conf. When I did the loop out from RTL I set a large block confirmation time (I believe it was 200). I have successfully looped out some different channels since I just left the default confirmation block time on those ones.

[bitromortac]

Here's what I think happens:

1. user does a loop out on UI, sets large confirmation target
2. UI fetches a quote from the loop server, where a low MinerFee is returned
3. UI takes MinerFee and sets it as MaxMinerFee (in loop cli MinerFee is multiplied with 250 to calculate MaxMinerFee)
4. because there is a slight discrepancy between the fee estimation of the server's MinerFee and the client's for large confirmation targets around here, the swap is never executed

[knox203]

Has there been any update to this? If it's a bug, it just bit me. Got charged 30k sats by the server on a 250k sat loop-out failure.

Then I have a successful loop-out that shows a 2,165 server charge, but the Transactions log shows I was charged 30k sats.

[guggero]

There have been several fixes for this, yes. Are you on the latest version of Loop?

[knox203]

Hi guggero, thanks for your reply! I was running v0.21.0-beta.

[guggero]

Okay, that is recent enough. Then I'm afraid you have to check the Loop logs to see why your daemon didn't pull the HTLC on chain. If the 30k sats are deducted, it means the server placed the transaction on chain but then your client didn't pull the funds for some reason. Could it be that you specified the max on-chain fees too low so the client wasn't able to pull the funds with the fee specified?

[elmeriniemela]

I had a similar issue.

I was using --conf_target 250, and then lnd was restated at 19:00. I'm new to lightning, and I would like to learn what went wrong. Thanks!

Logs: loopd.log

[hieblmi]

@elmeriniemela, in short your node paid the initial 30k sats prepay invoice that is used as a compensation for the loop-service to lock funds towards your loop out. This amount is reimbursed if you finalize the swap. For some reason your loop client did not complete the swap but timed out hence the prepay amount was not reimbursed. Apart from the log do you have any previous/later loop logs we can use to investigate?

EDIT: Another question. After you initiated the loop out did you then shut down your instance of loopd?

[elmeriniemela]

Hi @hieblmi

Thanks for the reply. I think the whole "loop out transaction" is recorded in the logs file I sent in the previous reply from start to failure. Let me walk through the sequence of events:

I requested a loop out at 18:27 (Finnish time UTC +3), with --conf_target 250 (i have a feeling that this param was a mistake by me) 2023-10-01 18:27:32.405 [INF] LOOPD: Loop out request received

Then, during the next 30 minutes, it was checking for the preimage in three different blocks (I'm not sure what the the hltc/payment lines after the first preimage check mean):

2023-10-01 18:27:36.114 [INF] LOOP: ac247f Register 1 conf ntfn for swap script on chain (hh=810171)
2023-10-01 18:27:36.114 [INF] LOOP: ac247f Checking preimage reveal height 810401 exceeded (height 810171)
2023-10-01 18:27:36.114 [INF] LOOP: ac247f Waiting for either htlc on-chain confirmation or off-chain payment failure
2023-10-01 18:27:38.712 [INF] LOOP: ac247f Acquired routing plugin Low/High for payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3
2023-10-01 18:27:38.712 [INF] LOOP: ac247f Payment (ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3) try count 1/3 (plugin=Low/High)
2023-10-01 18:27:38.712 [INF] LOOP: ac247f Payment (d2d707057ec2fa90f10dbbf3e1c026c85b671fa9ca431a7a7b3253d91b4248cd) try count 1/1 (plugin=None)
2023-10-01 18:27:38.729 [INF] LOOP: ac247f Payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3: state=IN_FLIGHT, inflight_htlcs=0, inflight_amt=0 mSAT
2023-10-01 18:27:38.729 [INF] LOOP: ac247f Payment d2d707057ec2fa90f10dbbf3e1c026c85b671fa9ca431a7a7b3253d91b4248cd: state=IN_FLIGHT, inflight_htlcs=0, inflight_amt=0 mSAT
2023-10-01 18:27:38.783 [INF] LOOP: ac247f Payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3: state=IN_FLIGHT, inflight_htlcs=1, inflight_amt=971180000 mSAT
2023-10-01 18:27:38.848 [INF] LOOP: ac247f Payment d2d707057ec2fa90f10dbbf3e1c026c85b671fa9ca431a7a7b3253d91b4248cd: state=IN_FLIGHT, inflight_htlcs=1, inflight_amt=30000000 mSAT
2023-10-01 18:27:39.874 [INF] LOOP: ac247f Payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3: state=IN_FLIGHT, inflight_htlcs=0, inflight_amt=0 mSAT
2023-10-01 18:27:39.970 [INF] LOOP: ac247f Payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3: state=IN_FLIGHT, inflight_htlcs=1, inflight_amt=971180000 mSAT
2023-10-01 18:27:40.814 [INF] LOOP: ac247f Payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3: state=IN_FLIGHT, inflight_htlcs=0, inflight_amt=0 mSAT
2023-10-01 18:27:40.979 [INF] LOOP: ac247f Payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3: state=IN_FLIGHT, inflight_htlcs=1, inflight_amt=971180000 mSAT
2023-10-01 18:28:02.316 [INF] LOOPD: Monitor request received
2023-10-01 18:29:39.417 [INF] LOOP: Received block 810172
2023-10-01 18:29:39.417 [INF] LOOP: ac247f Checking preimage reveal height 810401 exceeded (height 810172)
2023-10-01 18:58:39.045 [INF] LOOP: Received block 810173
2023-10-01 18:58:39.045 [INF] LOOP: ac247f Checking preimage reveal height 810401 exceeded (height 810173)

Then at 19:00, LND was restarted causing loopd to crash (had a cron to restart lnd every hour):

2023-10-01 18:58:39.045 [INF] LOOP: ac247f Checking preimage reveal height 810401 exceeded (height 810173)
2023-10-01 19:00:03.156 [ERR] LOOP: ac247f Swap error: rpc error: code = Unknown desc = chain notifier shutting down
2023-10-01 19:00:03.157 [INF] LOOP: ac247f Loop out swap state: FailTemporary
2023-10-01 19:00:03.157 [ERR] LOOP: Swap client terminating: block error: rpc error: code = Unknown desc = chain notifier shutting down
2023-10-01 19:00:03.160 [ERR] LOOP: Execute error: rpc error: code = Unknown desc = chain notifier shutting down
2023-10-01 19:00:03.160 [INF] LOOP: Swap client terminated
2023-10-01 19:00:03.160 [INF] LOOPD: Swap client stopped
2023-10-01 19:00:03.160 [ERR] LOOPD: Runtime error in daemon, shutting down: block error: rpc error: code = Unknown desc = chain notifier shutting down
2023-10-01 19:00:03.161 [INF] LOOPD: Stopping gRPC server
2023-10-01 19:00:03.161 [WRN] LOOP: ac247f Failed to report routing result: rpc error: code = Canceled desc = context canceled
2023-10-01 19:00:03.161 [INF] LOOPD: Liquidity manager stopped
2023-10-01 19:00:03.161 [INF] LOOPD: Stopping REST server
2023-10-01 19:00:03.174 [INF] LOOPD: Daemon exited

A minute later, I restarted loopd, but the swap failed with state "FailOffchainPayments":

2023-10-01 19:01:13.444 [INF] LOOPD: Version: 0.26.3-beta commit=
2023-10-01 19:01:13.445 [INF] LNDC: Creating lnd connection to localhost:10009
2023-10-01 19:01:13.446 [INF] LNDC: Connected to lnd
2023-10-01 19:01:13.453 [INF] LNDC: Waiting for lnd to unlock
2023-10-01 19:01:13.454 [INF] LNDC: Wallet state of lnd is now: Lnd main server is ready for requests
2023-10-01 19:01:15.191 [INF] LNDC: lnd version: v0.17.0-beta.rc6, build tags 'signrpc,walletrpc,chainrpc,invoicesrpc'
2023-10-01 19:01:15.191 [INF] LNDC: Using network mainnet
2023-10-01 19:01:15.191 [INF] LNDC: Waiting for lnd to be fully synced to its chain backend, this might take a while
2023-10-01 19:01:15.571 [INF] LNDC: lnd is now fully synced to its chain backend
2023-10-01 19:01:15.571 [INF] LOOPD: Protocol version: MuSig2
2023-10-01 19:01:15.571 [INF] LOOPD: Swap server address: swap.lightning.today:11010
2023-10-01 19:01:15.571 [INF] LOOPD: Found sqlite db at /home/elmeri/.loop/mainnet/loop_sqlite.db, skipping migration
2023-10-01 19:01:15.571 [INF] LOOPD: Opening sqlite3 database at: /home/elmeri/.loop/mainnet/loop_sqlite.db
2023-10-01 19:01:15.656 [INF] LOOPD: Starting swap client
2023-10-01 19:01:15.656 [INF] LOOPD: Starting liquidity manager
2023-10-01 19:01:15.656 [INF] LOOP: Connected to lnd node '03b7dd0e2a6a0d89a3c3' with pubkey 03b7dd0e2a6a0d89a3c3ab883c070643fa8b36694e6a61d83a1a53b7c8f394cd1b (version v0.17.0-beta.rc6, build tags 'signrpc,walletrpc,chainrpc,invoicesrpc')
2023-10-01 19:01:15.656 [INF] LOOPD: Starting gRPC listener
2023-10-01 19:01:15.656 [INF] LOOPD: Waiting for updates
2023-10-01 19:01:15.657 [INF] LOOPD: Starting REST proxy listener
2023-10-01 19:01:15.657 [INF] LOOPD: RPC server listening on 127.0.0.1:11010
2023-10-01 19:01:15.657 [INF] LOOP: Wait for first block notification
2023-10-01 19:01:15.657 [INF] LOOP: Resuming loop out swap ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3
2023-10-01 19:01:15.657 [INF] LOOPD: REST proxy listening on 127.0.0.1:8081
2023-10-01 19:01:15.657 [INF] LOOP: ac247f Htlc address: bc1pd08t6n68ar6ggke96fejyqd6q0fg56gcg027fdmvj66868r472rs3h407z
2023-10-01 19:01:15.657 [INF] LOOP: Starting event loop at height 810173
2023-10-01 19:01:15.663 [INF] LOOP: ac247f Loop out swap state: Initiated
2023-10-01 19:01:15.663 [INF] LOOP: ac247f Sending swap payment lnbc9711800n1pj3nrl8pp54sj8la6fxrqkq3lgyxlmllumxeypsxs3ywgq7v3ggdrndf756hfsdy9wdmkzupq95s8xcmjd9c8gw3qx5cnyvpkvf3k2cnyx3nrgdm98pnrgwp5x43rydtyxgmnxv3jxqckycfsxdjrywrpxcunzwp5xdjr2ef5vgmnvceexe3rgdmyx93nwdtxxgurwcqz27xq97zvuqrzjqgwf02g2gy0l9vgdc25wxt0z72wjlfyagxlmk54ag9hyvrdsw37smapyqqqqqqqq2qqqqqqqqqqqqqqq9qsp55eurpxsej7g0qgptl6lcc48xcykyjnk45je60ga0vgc8trf7mths9qyyssqpe9cj5fkgsleqr9qqwqautth53y833htsvpm70axgq00knhy4jfhv9980gpwu72s3l0tufvvehas4y08r7ps25d6955sx406plfcj7qpvg09hq
2023-10-01 19:01:16.877 [INF] LOOP: ac247f Server recommended routing plugin: Low/High
2023-10-01 19:01:16.877 [INF] LOOP: ac247f Sending prepayment lnbc300u1pj3nrl8pp56ttswpt7ctafpugdh0e7rspxepdkw8afefp357nmxffajx6zfrxsdq2wpex2urp0ycqz27xq97zvuqrzjqgwf02g2gy0l9vgdc25wxt0z72wjlfyagxlmk54ag9hyvrdsw37smapyqqqqqqqq2qqqqqqqqqqqqqqq9qsp5rkm4eeljgzayh0yq24pv0ne0zljnsgrh4qd9n52npfef0gpmve5s9qyyssqf82h3us9ffeg2nvk5n4tugc5p8t3qylnsl83gw9jtkar3gdf6qchateddqhp922952j5fa0kwf0lqw43vveh8mtr5ezf3e6jscv8rxcqqvz4cm
2023-10-01 19:01:16.877 [INF] LOOP: ac247f Register 1 conf ntfn for swap script on chain (hh=810171)
2023-10-01 19:01:16.878 [INF] LOOP: ac247f Checking preimage reveal height 810401 exceeded (height 810173)
2023-10-01 19:01:16.878 [INF] LOOP: ac247f Waiting for either htlc on-chain confirmation or off-chain payment failure
2023-10-01 19:01:16.879 [INF] LOOP: ac247f Payment (d2d707057ec2fa90f10dbbf3e1c026c85b671fa9ca431a7a7b3253d91b4248cd) try count 1/1 (plugin=None)
2023-10-01 19:01:16.903 [INF] LOOP: ac247f Failed prepayment: rpc error: code = Unknown desc = payment is in transition
2023-10-01 19:01:16.903 [INF] LOOP: ac247f Canceling swap: 1 payment failed: FAILURE_REASON_NONE, 0 attempts
2023-10-01 19:01:17.087 [INF] LOOP: ac247f Server update: SERVER_INITIATED received, timestamp: 2023-10-01 18:27:35.720577732 +0300 EEST
2023-10-01 19:01:17.108 [INF] LOOP: ac247f Wait for server pulling off-chain payment(s)
2023-10-01 19:01:20.019 [INF] LOOP: ac247f Acquired routing plugin Low/High for payment ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3
2023-10-01 19:01:20.019 [INF] LOOP: ac247f Payment (ac247ff74930c16047e821bfbfff9b3648181a1123900f3228434736a7d4d5d3) try count 1/3 (plugin=Low/High)
2023-10-01 19:01:20.247 [INF] LOOP: ac247f Swap payment failed: rpc error: code = Unknown desc = payment is in transition
2023-10-01 19:01:20.247 [INF] LOOP: ac247f Swap completed: FailOffchainPayments (final cost: server 0 BTC, onchain 0 BTC, offchain 0 BTC)
2023-10-01 19:01:20.261 [INF] LOOP: ac247f Loop out swap state: FailOffchainPayments

After that, there is nothing in the logs for ~50mins between the 19:01:20 "FailOffchainPayments" and the following log line at the end of the file at which point I did a restart: 2023-10-01 19:49:59.079 [INF] LOOPD: Liquidity manager stopped

After the restart I did some monitoring calls and tried to start a new "loop out" but the funds were suspended so it didn't even start. I can send you more logs, but I can only see restarts made every hour by the cron and nothing related to this failed loop out. ~2 days later, I received the refund on the chain and did another loop out (with --conf_target=9) that worked almost immediately without any issues.

So my guess is that --conf_target=250 + restarting the LND caused the issue, what do you think?

[hieblmi]

Hi, thanks for the detailed report. I am still not sure about the exact cause for the first swap to fail. It could have been that the first swap payment failed due to a liquidity/path finding issue on the route your node -> Kraken -> ... -> LOOP. But since the pre-payment of 30k made it that's unlikely. What is more likely is that the high conf-target impacted the settlement time of the swap invoice - which then timed out and failing the swap. This seems likely the cause since the lower conf target worked.

I don't think the interruption of loop during a pending swap was the cause for the failure. But why schedule restarts of lnd?