client/asset, core: lock and return coins when needed #525

buck54321 · 2020-07-03T01:07:26Z

Lock change coin in ExchangeWallet.Swap. Return unused coins when an order is canceled, or when a market is suspended with persist = false.

JoeGruffins

I am noticing some errors that appear frequently. This is one:

2020-07-06 11:30:47.670 [DBG] CORE[dcr]: 1 signature cycles to converge on fees for tx 6f241290f324623cbb8483d63100e5299ad48e28fb826df830baa9de0fe88b76
2020-07-06 11:30:47.672 [ERR] CORE: notify: |ERROR| (order) Swap error - Error encountered sending a swap output(s) worth 1.00000000 dcr on order f64246d3 - Order: f64246d373ce98bfec117e4eafd7e9b0695565f343d9301e52f41896f597bb55
2020-07-06 11:30:47.672 [ERR] CORE: 127.0.0.1:7232 tick error: 127.0.0.1:7232 tick: swapMatches order f64246d373ce98bfec117e4eafd7e9b0695565f343d9301e52f41896f597bb55 - error sending swap transaction: -4: rejected transaction 6f241290f324623cbb8483d63100e5299ad48e28fb826df830baa9de0fe88b76: transaction 6f241290f324623cbb8483d63100e5299ad48e28fb826df830baa9de0fe88b76 has insufficient priority (0 <= 5.76e+07)
2020-07-06 11:30:47.679 [DBG] CORE[dcr]: 1 signature cycles to converge on fees for tx a1cef25f8cd73489b6452ce420d9901cf90ef40b6107a8035fc5516b1ac4a9d8
2020-07-06 11:30:47.681 [ERR] CORE: notify: |ERROR| (order) Swap error - Error encountered sending a swap output(s) worth 1.00000000 dcr on order 35939081 - Order: 3593908179a89dc979bf78bc44bd69b0c5efe92afa24a307b095dc4af500925f
2020-07-06 11:30:47.681 [ERR] CORE: 127.0.0.1:7232 tick error: 127.0.0.1:7232 tick: swapMatches order 3593908179a89dc979bf78bc44bd69b0c5efe92afa24a307b095dc4af500925f - error sending swap transaction: -4: rejected transaction a1cef25f8cd73489b6452ce420d9901cf90ef40b6107a8035fc5516b1ac4a9d8: transaction a1cef25f8cd73489b6452ce420d9901cf90ef40b6107a8035fc5516b1ac4a9d8 has insufficient priority (0 <= 5.76e+07)

and

2020-07-06 10:47:34.889 [DBG] CORE[btc]: 2 signature cycles to converge on fees for tx e8d30d290c537b99cdd5378f88b73ee1c7bd8f5563228e2f52194ae0a648e2ac
2020-07-06 10:47:34.891 [ERR] CORE: notify: |ERROR| (order) Swap error - Error encountered sending a swap output(s) worth 1.00000000 btc on order b27ddeb7 - Order: b27ddeb73516a49467f30a4573329ac96a9973a58bb77be7e94277293042c93c
2020-07-06 10:47:34.891 [ERR] CORE: 127.0.0.1:7232 tick: swapMatches order b27ddeb73516a49467f30a4573329ac96a9973a58bb77be7e94277293042c93c - error sending swap transaction: -26: min relay fee not met, 0 < 165 (code 66)

and

2020-07-06 12:03:03.931 [WRN] CORE: notify: |WARNING| (order) Match revoked - Match dc4bd9cb has been revoked - Order: dc4bd9cb1f4948bd2fb55084db75c8557cfd0482da89d22d59cd9cc9cd3acfb4
2020-07-06 12:03:03.931 [TRC] CORE: notify: |DATA| (order) revoke - Order: 
2020-07-06 12:03:03.933 [WRN] CORE: unable to unlock funding coin 611109699fe2d5067e7470d1a733e4db86ccd75cba7ad4396ae80e362d93a64b:1: rawrequest error: -8: Invalid parameter, expected unspent output
2020-07-06 12:03:03.934 [WRN] CORE: unable to unlock funding coin a9977fae06cee24365b9cfbaa50930df6ae4f62738c9dacb9779e312c90a8288:2: rawrequest error: -8: Invalid parameter, expected locked output
2020-07-06 12:03:03.935 [WRN] CORE: unable to unlock change coin a9977fae06cee24365b9cfbaa50930df6ae4f62738c9dacb9779e312c90a8288:2: rawrequest error: -8: Invalid parameter, expected locked output
2020-07-06 12:03:03.944 [TRC] CORE: notify: |DATA| (balance) balance updated
2020-07-06 12:03:03.944 [WRN] CORE: Match 7aceaa486c9be977e88405a7fa4694466479639d284bca3c3aac74e000fea9dd revoked in status TakerSwapCast for order dc4bd9cb1f4948bd2fb55084db75c8557cfd0482da89d22d59cd9cc9cd3acfb4

Any of which leads to my account being penalized.

Another error to pop up:

2020-07-06 11:58:43.041 [ERR] CORE: notify: |ERROR| (order) Order coin error - Source coins retrieval error for btc dc4bd9cb: funding coin a9977fae06cee24365b9cfbaa50930df6ae4f62738c9dacb9779e312c90a8288:2 not found - Order: dc4bd9cb1f4948bd2fb55084db75c8557cfd0482da89d22d59cd9cc9cd3acfb4

Sometimes, after wiping my client db, and trying to place my first order:

2020-07-06 10:50:37.009 [ERR] WEB: error placing order: rpc error: 35: coin {txid = 329e12d9994b153b1842f944c545801f5da759b380b41727a73d1594cd73e6ec, vout = 0} is locked

And while not an error, this debug list gets longer and longer as I trade:

2020-07-06 11:31:52.949 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. 26218cf68b038e1536b57b9789af9c97309f7423e0bc5c3e6c309d6cdbded7a3:5
2020-07-06 11:31:52.949 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. 65a32b75d9291f29895ca323aed4aa7bc5f86612f6aec0ec34a96564d265e2e1:1
2020-07-06 11:31:52.949 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. afdec2bef6aa91a149c55a1257862d6df97fa949bf56d33ae8bc11865e2ce6d0:1
2020-07-06 11:31:52.950 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. 8d03458c2960acf4ef9555b59810dcd641a97400d71d9b31eeb89c74fec6608f:1
2020-07-06 11:31:52.950 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. ecc13c9ffd1c2f837e7a302462697bd19c529504f9fb3091311e0a9fd495a88c:5

Some of these may be in master. I will go through and try to find out exactly what is causing them and write up some issues

JoeGruffins · 2020-07-06T00:35:38Z

client/asset/btc/btc.go

+
+	// Lock the change outpoint in case it is still required to fund chained
+	// swaps for an order.
+	err = btc.wallet.LockUnspent(false, []*output{change})


Should these also be added to btc.fundingCoins at this time? It looks like you are with dcr, which has a differently named method dcr.lockFundingCoins

chappjc · 2020-07-06T16:06:30Z

The min relay fee not met error is of course #529 and I think that's because the server isn't recompiled and the client gets 0 for the swap fee rate that is not sensible. The other errors probably stem from that.

chappjc

Tested with about 10 orders locking almost all of the wallets, including several partial fills creating locked change outputs, and a swap where the txn included multiple contract outputs. Only comments from testing are that some more verbose logging would be nice. Moving to code review now.

chappjc

Without cancels, just executed orders, coins are remaining locked.

In addition to more unlocking needed in swapMatches for executed orders, unmatched market and immediate limits need their funding coins unlocked somewhere too, although it's not clear if that should happen via: (1) handleMatchProofMsg (painful and error prone), (2) if 'match' should include special matches to indicate no match for a given taker order, or (3) for each epoch order consider it unmatched if it is not the in 'match' message.

client/core/trade.go

chappjc · 2020-07-06T19:34:00Z

client/core/trade.go

@@ -746,6 +759,12 @@ func (t *trackedTrade) swapMatches(matches []*matchTracker) error {
 		}
 	}

+	// Check if we need to return the change coin because the order has been
+	// canceled.
+	if t.metaData.Status == order.OrderStatusCanceled && !t.hasUnswappedMatches() {


A comment I made in my draft PR at 98cc346#diff-5c4d3ee4527d6c50d1379b8edb5ef11eR221-R224 was about the locking around these trackedTrade fields. Are we sure there are no concurrent read/writes possible? It's not clear to me what trackedTrade.mtx is meant to guard.

buck54321 · 2020-07-10T13:04:30Z

Converting back to draft temporarily. Essentially untested, but open to critique.

chappjc · 2020-07-13T14:43:08Z

@JoeGruffins

And while not an error, this debug list gets longer and longer as I trade:

2020-07-06 11:31:52.949 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. 26218cf68b038e1536b57b9789af9c97309f7423e0bc5c3e6c309d6cdbded7a3:5
2020-07-06 11:31:52.949 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. 65a32b75d9291f29895ca323aed4aa7bc5f86612f6aec0ec34a96564d265e2e1:1
2020-07-06 11:31:52.949 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. afdec2bef6aa91a149c55a1257862d6df97fa949bf56d33ae8bc11865e2ce6d0:1
2020-07-06 11:31:52.950 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. 8d03458c2960acf4ef9555b59810dcd641a97400d71d9b31eeb89c74fec6608f:1
2020-07-06 11:31:52.950 [DBG] CORE[dcr]: ignoring output from listlockunspent that wasn't found with gettxout. ecc13c9ffd1c2f837e7a302462697bd19c529504f9fb3091311e0a9fd495a88c:5

This is #471 and it deserves investigation.

Sometimes, after wiping my client db, and trying to place my first order:

2020-07-06 10:50:37.009 [ERR] WEB: error placing order: rpc error: 35: coin {txid = 329e12d9994b153b1842f944c545801f5da759b380b41727a73d1594cd73e6ec, vout = 0} is locked

Wiping your client DB doesn't cancel the orders server-side. This error says the server still has the coin locked. Possibly the server is incorrect here, but it makes sense that this can happen when you wipe the client and try to place new orders with the same wallet.

buck54321 · 2020-07-14T19:17:29Z

I think there's a little more debugging to do after #531 is in, but this can be reviewed. Removing from draft.

buck54321 · 2020-07-14T20:01:09Z

client/asset/btc/btc.go

-	// Unlock the utxos and delete them from the cache.
-	err = btc.wallet.LockUnspent(true, spents)
-	if err != nil {
-		btc.log.Errorf("failed to unlock spent outputs: %v", err)
-	}
+	// Delete the UTXOs from the cache.


Turns out bitcoind already removes the spent outputs. bitcoin/bitcoin#13160

chappjc

Quick look at the latest changes, looking good. I have some questions, but overall it looks like it will solve the change locking issues.

server/matcher/match.go

server/market/market.go

dex/msgjson/types.go

client/core/trade.go

client/asset/interface.go

client/core/trade.go

chappjc · 2020-07-17T20:59:20Z

One thing that I noticed on master is that when dexc starts up, the existing order coins show as locked in the wallet. I'm pretty sure the following is just a GUI bug, but my dexc shows the following even though I have the majority of both wallets funds locked in active orders

listlockunspent lists numerous locked outputs, so I think it's just the gui.

EDIT: Placing an order updates the locked component. Seems like a refresh balances button would be nice to have.

client/asset/btc/btc.go

client/core/trade.go

chappjc

Looks good, although I need to take it for another spin, and I think having a log entry for each lock/unlock coins event would be very helpful for debugging.

server/matcher/match.go

chappjc · 2020-07-20T20:09:47Z

Tested by building up the books, and filling all the orders in different ways (partial fills, immediate limits, multiple matches per order in an epoch, market buys and sells, etc.). No trouble, and the coin lock/unlock log messages I added to the client/asset/{btc,dcr} packages made sense. I have a stash with these log changes that I can push into another PR unless you've got any final edits for this @buck54321.

Only thing that stood out is that we still need to clean out completed trades because even at the end I was seeing [DBG] CORE: ticking 31 trades, but that's not something with this PR.

server/matcher/match.go

client/asset/btc/btc.go

buck54321 mentioned this pull request Jul 3, 2020

spec: maxfeerate, revoke_order, preimage response ack, feedless orderbook #526

Closed

JoeGruffins reviewed Jul 6, 2020

View reviewed changes

chappjc reviewed Jul 6, 2020

View reviewed changes

chappjc requested changes Jul 6, 2020

View reviewed changes

buck54321 mentioned this pull request Jul 7, 2020

spec: add nomatch notification #535

Merged

chappjc mentioned this pull request Jul 9, 2020

dex/order,client/asset: fix UserMatch DB serialization, and change address assumption #531

Merged

buck54321 marked this pull request as draft July 10, 2020 13:03

buck54321 force-pushed the returncoins branch from 4be7109 to 88004c6 Compare July 14, 2020 02:33

buck54321 marked this pull request as ready for review July 14, 2020 19:17

buck54321 commented Jul 14, 2020

View reviewed changes

chappjc reviewed Jul 14, 2020

View reviewed changes

buck54321 added 8 commits July 17, 2020 14:20

lock and return coins when needed

5895d3f

add LockChange field to asset.Swaps. Unlock spent coins in Wallet.Swap.

d95b246

Add nomatch requests. simplify core mutex locking

901fb93

more tests. fixes and tweaks.

c26cbab

skip tick for completed matches

550fd6e

mutex scheme: take 2

314c775

hold tradeMtx longer when placing order

8265a93

various bug fixes

53b9400

buck54321 added 3 commits July 20, 2020 06:28

add change to fundingCoin map

e04deae

review fixes

2b5a05f

update balances for coins locked on startup

ffb978a

buck54321 force-pushed the returncoins branch from 3667a2e to ffb978a Compare July 20, 2020 13:02

chappjc reviewed Jul 20, 2020

View reviewed changes

client/asset/btc/btc.go Show resolved Hide resolved

fix change locking for immediate orders

d0fc3ec

chappjc reviewed Jul 20, 2020

View reviewed changes

client/core/trade.go Outdated Show resolved Hide resolved

even simpler

870141a

chappjc approved these changes Jul 20, 2020

View reviewed changes

server/matcher/match.go Show resolved Hide resolved

touchups

9504788

buck54321 commented Jul 20, 2020

View reviewed changes

server/matcher/match.go Show resolved Hide resolved

chappjc reviewed Jul 20, 2020

View reviewed changes

client/asset/btc/btc.go Show resolved Hide resolved

more logging. less logging.

402f541

chappjc merged commit a986320 into decred:master Jul 20, 2020

chappjc mentioned this pull request Jul 20, 2020

client: order recorded after submission #544

Closed

buck54321 mentioned this pull request Aug 20, 2020

client/core: change coins must be locked in wallet for partially filled limits #510

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

client/asset, core: lock and return coins when needed #525

client/asset, core: lock and return coins when needed #525

buck54321 commented Jul 3, 2020

JoeGruffins left a comment

JoeGruffins Jul 6, 2020

chappjc commented Jul 6, 2020

chappjc left a comment •

edited

Loading

chappjc left a comment •

edited

Loading

chappjc Jul 6, 2020 •

edited

Loading

buck54321 commented Jul 10, 2020

chappjc commented Jul 13, 2020 •

edited

Loading

buck54321 commented Jul 14, 2020

buck54321 Jul 14, 2020

chappjc left a comment

chappjc commented Jul 17, 2020 •

edited

Loading

chappjc left a comment

chappjc commented Jul 20, 2020

client/asset, core: lock and return coins when needed #525

client/asset, core: lock and return coins when needed #525

Conversation

buck54321 commented Jul 3, 2020

JoeGruffins left a comment

Choose a reason for hiding this comment

JoeGruffins Jul 6, 2020

Choose a reason for hiding this comment

chappjc commented Jul 6, 2020

chappjc left a comment • edited Loading

Choose a reason for hiding this comment

chappjc left a comment • edited Loading

Choose a reason for hiding this comment

chappjc Jul 6, 2020 • edited Loading

Choose a reason for hiding this comment

buck54321 commented Jul 10, 2020

chappjc commented Jul 13, 2020 • edited Loading

buck54321 commented Jul 14, 2020

buck54321 Jul 14, 2020

Choose a reason for hiding this comment

chappjc left a comment

Choose a reason for hiding this comment

chappjc commented Jul 17, 2020 • edited Loading

chappjc left a comment

Choose a reason for hiding this comment

chappjc commented Jul 20, 2020

chappjc left a comment •

edited

Loading

chappjc left a comment •

edited

Loading

chappjc Jul 6, 2020 •

edited

Loading

chappjc commented Jul 13, 2020 •

edited

Loading

chappjc commented Jul 17, 2020 •

edited

Loading