Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

client/core: async req/ntfn handling, parallel new match negotiation #565

Merged
merged 3 commits into from
Aug 6, 2020

Conversation

chappjc
Copy link
Member

@chappjc chappjc commented Jul 22, 2020

Resolves #554 and a few untracked issues

Main changes:

  • Async incoming request/notification handling in client/core, no longer blocking
  • Parallel client negotiation of trades with new matches (still sequential for a given trade)
  • Configurable client request expiration
  • Longer request timeouts for client's init and redeem requests, where the server
    may wait up to broadcast timeout to respond.
  • Longer timeout on client's coin waiters for processAudit and notifyFee
  • Longer timeout on server's audit request
  • Fix client outgoing messages not first being validated before writing to link

client/core

Incoming requests and notifications queue the call to the registered
handler function in a dedicated runner goroutine now to prevent
blocking subsequent reqs/ntfns. If the channel buffer fills, handling
becomes blocking again, as it was before this change.

(*dexConnection).runMatches now starts negotiation of a trade's new
matches in parallel since runMatches>tick>{swap,redeem,refund}Matches
can block for a long time waiting for a response from the server.

In handleMatchRoute, wait briefly before runMatches to reduce the chance
that the server will not have yet saved the match ack sig sent just
prior. On the server side, processMatchAcks now locks all of the
involved matchTrackers right out of the gates, before processing the
client's acks. This is still a race, but it cannot be fully resolved
until/unless the client can get an OK/done back from it's own ack
response to the original match requests. However, resendPendingRequests
will retry failed 'init' requests so this is not a show stopper bug.

Do not try to swap/redeem/refund cancel matches in (*trackedTrade).tick.

Tweak errorSet formatting to reflect a set, and rename ifany to ifAny.

client/{core,comms}

Add comms.WsConn.RequestWithTimeout, implemented by wsConn.
RequestWithTimeout has a expire/response timeout duration and expire
callback input args.

Add comms.DefaultRequestTimeout for use in vanilla Request, and by
consumers that wish to set an expire function, but no particular timeout.

(*dexConnection).signAndRequest now accepts a timeout duration.

Remove core.txWaitExpiration, which was arbitrary and not coordinated
with the server. Instead use broadcast timeout in:

  • finalizeSwapAction>signAndRequest, where the server waits for an
    unspecified time that could be up to broadcast timeout.
  • finalizeRedeemAction>signAndRequest, for the same reasons as above
  • processAudit>latencyQ.Wait, since there is no reason to give up sooner
  • notifyFee, for the same reason as processAudit.

However, there may be reason to timeout sooner in the init and redeem
requests if the client thinks resending the request might help.

The DefaultRequestTimeout is used in:

  • place cancel order request
  • place trade order request
  • register request
  • connect request (authDEX)
  • config request (connectDEX)

TODO: If the server responds to init or redeem with an Error payload
with Code TransactionUndiscovered, the client may try to rebroadcast the
transaction that the server couldn't find, specially if the response
comes well in advance of broadcast timeout (penalization time).

server/swap

The audit request timeout should be up to broadcast timeout, but not for
the redemption request where the client does not need to check the coin
network.

Also hold the match mtx locked and check that the match isn't revoked
before storing results in processInit and processRedeem.

client/comms: marshal before attempting link write

In client/comms.(*wsConn).Send, marshal the Message first so that we
do not send junk to the peer even if it fails to marshal completely,
which WriteJSON does.

Test marshal error with Send/Request, and removal of response handler
in this case with Request.

Test RequestWithTimeout expiration handler and response handler removal.

@chappjc chappjc force-pushed the async-client-inhandler branch 3 times, most recently from b020561 to 905e6c3 Compare July 24, 2020 16:36
@chappjc chappjc marked this pull request as ready for review July 24, 2020 16:51
client/core/core.go Show resolved Hide resolved
client/core/core.go Show resolved Hide resolved
client/core/core.go Show resolved Hide resolved
client/core/core.go Show resolved Hide resolved
client/core/core.go Show resolved Hide resolved
Comment on lines 2864 to 3056
// TODO: We need to know that the server has first recorded the ack
// signature, otherwise 'init' will fail. Until this is solved with a
// response to the ack, sleep for a moment if we are the maker on any of the
// orders. However, resendPendingRequests will retry the request when the
// trackedTrack ticks again when the timer fires in listen.
for _, m := range msgMatches {
if m.Side == uint8(order.Maker) {
time.Sleep(250 * time.Millisecond)
Copy link
Member Author

@chappjc chappjc Jul 24, 2020

Choose a reason for hiding this comment

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

Another use case for a response to a response, or a more general "dialog" or sequence of responses. Even if the match ack was successfully sent just above, runMatches just below (and init broadcast/request) can happen immediately for a maker's match. This is a race with the server's handling of the match ack because until it stores the ack signature it won't be ready for the init! It's not a terrible problem though because resendPendingRequests will keep trying if it does fail because of this.

I'm now trying to mitigate this race with (1) the sleep here, and (2) on the server by locking the matches mutex early in (*Swapper).processMatchAcks (https://github.com/decred/dcrdex/pull/565/files#diff-5f1d20749025f318cd1a8ba0915ebd37R2110-R2126), but it's still a race AFAICT. The best solution would be for the client to get confirmation that the match ack was received (and recorded) before attempting the init.

client/core/core_test.go Show resolved Hide resolved
client/core/trade.go Outdated Show resolved Hide resolved
client/core/trade.go Outdated Show resolved Hide resolved
client/core/trade.go Show resolved Hide resolved
Copy link
Member

@buck54321 buck54321 left a comment

Choose a reason for hiding this comment

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

Lots of good stuff here. I see that maybe you're waiting on #566, so I'll get that out of draft now.

client/core/core.go Outdated Show resolved Hide resolved
client/core/core.go Outdated Show resolved Hide resolved
client/core/core.go Outdated Show resolved Hide resolved
client/core/trade.go Outdated Show resolved Hide resolved
errChan := make(chan error, 1)
var auditInfo asset.AuditInfo
t.latencyQ.Wait(&wait.Waiter{
Expiration: time.Now().Add(txWaitExpiration),
Expiration: time.Now().Add(t.broadcastTimeout()),
Copy link
Member

Choose a reason for hiding this comment

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

It's not clear to me that the broadcast timeout is the right value for latency expiration. They seem unrelated. Is there a good reason to use the broadcast timeout here?

Copy link
Member Author

Choose a reason for hiding this comment

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

After broadcast timeout, the waiter might as well give up because the swap is going to be revoked. Before broadcast timeout, why give up?

Copy link
Member Author

@chappjc chappjc Jul 29, 2020

Choose a reason for hiding this comment

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

I can imagine the waiter printing "tx still not found" messages periodically so the user can check out their node's connectivity, but otherwise I don't see a reason to go with a shorter expiration. In this case, the client is asked by the server to audit a contract transaction, and they have until broadcast timeout to do it before they get penalized and the match revoked.

@chappjc chappjc force-pushed the async-client-inhandler branch from 905e6c3 to db23b03 Compare July 29, 2020 22:47
Comment on lines 396 to 385
}

// Now that each Match in msgMatches has been validated, store them in the
// trackedTrade and the DB, and update each order's status and fill amount.
// First record any cancel order Match and update order status.
if cancelMatch != nil {
t.cancel.matches.maker = cancelMatch // taker is stored via processCancelMatch before negotiate
// Set the order status for both orders.
t.metaData.Status = order.OrderStatusCanceled
t.db.UpdateOrderStatus(t.cancel.ID(), order.OrderStatusExecuted)
}
for _, match := range newTrackers {
t.matches[match.id] = match
Copy link
Member Author

Choose a reason for hiding this comment

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

In line with the any bad data = all bad data philosophy, the db and matches map are not updated until after each msgMatch is verified.

// field being an empty string.
isCancel := t.cancel != nil && msgMatch.Address == ""
if isCancel {
match.setStatus(order.MatchComplete)
Copy link
Member Author

@chappjc chappjc Jul 29, 2020

Choose a reason for hiding this comment

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

This setStatus must have been superfluous because the match for a cancel Match is not stored in the t.matches map or stored in the DB. Should this cancel msgMatch get a MetaMatch stored in the DB too like the others? The taker side of the match isn't stored either, so I think we aren't intending to store them, but I'm not sure.

So I think now that both cancel Matches should be getting stored in the DB (the maker side was at least being stored). Will have to look at this again.

Copy link
Member Author

@chappjc chappjc Jul 30, 2020

Choose a reason for hiding this comment

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

This is now addressed by storing both maker and taker cancel Matches in this diff set.
I think the taker's cancel Match not being stored previoiusly was a bug since the maker cancel Match was.

Copy link
Member

Choose a reason for hiding this comment

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

Thanks for this. This is the first step needed to fix

// TODO: The trackedTrade.cancel.matches is not being repopulated on

@chappjc chappjc force-pushed the async-client-inhandler branch from 9b32651 to c952eb9 Compare July 30, 2020 16:51
@chappjc
Copy link
Member Author

chappjc commented Jul 30, 2020

I think I'm done with updates to this one. I went back on allowing some matches to fail based on the "any bad data = all bad data" stance, but the one error in trade.tick() returning an error from (*dexConnection).runMatches still doesn't sit perfectly well with me since those will be ticked again (retried) later. https://github.com/decred/dcrdex/pull/565/files#diff-5c4d3ee4527d6c50d1379b8edb5ef11eR456 But the handleMatchRoute error is just logged and doesn't stop anything, so no biggie.

Open to suggestions for that, and for revising the TestTradeTracking test with invalidAcker being expected to cause an error from handleMatchRoute (via handleMatchRoute>runMatches>tick>swapMatches>finalizeSwapAction>signAndRequest>sendRequest>Request>invalidAcker), where I feel that the tick error should perhaps not rise back to handleMatchRoute (but now at least it does not break the other trade-matches in runMatches).

Comment on lines -346 to -370
Status: order.NewlyMatched,
Proof: db.MatchProof{
Auth: db.MatchAuth{
MatchSig: msgMatch.Sig,
MatchStamp: msgMatch.ServerTime,
},
},
DEX: t.dc.acct.host,
Base: t.Base(),
Quote: t.Quote(),
},
Match: &order.UserMatch{
OrderID: oid,
MatchID: mid,
Quantity: msgMatch.Quantity,
Rate: msgMatch.Rate,
Address: msgMatch.Address,
Status: order.MatchStatus(msgMatch.Status),
Copy link
Member Author

@chappjc chappjc Jul 30, 2020

Choose a reason for hiding this comment

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

Note that this previous code was potentially setting different Status values between the MatchMetaData and UserMatch. Since negotiate is intended to start new matches, I believe, I've updated this with a match.SetStatus(order.NewlyMatched) several lines down, while the new makeMetaMatch method ensures both Status values are consistent.

@chappjc chappjc force-pushed the async-client-inhandler branch from c952eb9 to 4683a75 Compare July 31, 2020 14:58
Copy link
Member

@JoeGruffins JoeGruffins left a comment

Choose a reason for hiding this comment

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

I was able to get to a point where the ticks are telling me this:

2020-08-01 12:14:00.219 [DBG] CORE: ticking 18 trades
2020-08-01 12:14:00.219 [DBG] CORE: Match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538 not swappable: failErr = -4: rejected transaction c5c607b8dbd2867a4e62ecb2e8d8e202e615970622377254dd8b9a1bd71fbf6d: transaction c5c607b8dbd2867a4e62ecb2e8d8e202e615970622377254dd8b9a1bd71fbf6d has 700000000 fee which is above the allowHighFee check threshold amount of 34800000, revoked = true
2020-08-01 12:14:00.219 [DBG] CORE: Match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538 not redeemable: failErr = -4: rejected transaction c5c607b8dbd2867a4e62ecb2e8d8e202e615970622377254dd8b9a1bd71fbf6d: transaction c5c607b8dbd2867a4e62ecb2e8d8e202e615970622377254dd8b9a1bd71fbf6d has 700000000 fee which is above the allowHighFee check threshold amount of 34800000, RefundCoin = 
2020-08-01 12:14:00.219 [TRC] CORE: Match not ready for action as Taker: 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538

Possibly the cause:

2020-08-01 12:12:20.071 [INF] CORE: Match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538 complete: sell 2900000000 dcr
2020-08-01 12:12:20.077 [INF] CORE: Notified of maker's redemption (btc: 6acde13ea466d5f4173a2e1b901755c3ecbda93e7dffe2ca7c98e90e006c6580:0) and validated secret for order 533aa78e7132f43e9437edfe86bd4d1af6104aa328ba11725ff80130334f1758...
2020-08-01 12:12:20.077 [DBG] CORE: notify: |POKE| (order) Match complete - Redeemed 0.29000000 btc on order e14f17d2 - Order: e14f17d23788de4f50c0c12928b4c1b842a262f174c87ddfd86f2c29e6ea6b2d
2020-08-01 12:12:20.079 [DBG] CORE: Redeemable match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538 for order 533aa78e7132f43e9437edfe86bd4d1af6104aa328ba11725ff80130334f1758 (Taker)
2020-08-01 12:12:20.080 [WRN] CORE[dcr]: Unable to get optimal fee rate, using fallback of 2000000: -4: no bucket with the minimum required success percentage found
2020-08-01 12:12:20.084 [ERR] CORE: notify: |ERROR| (order) Redemption error - Error encountered sending redemptions worth 29.00000000 dcr on order 533aa78e - Order: 533aa78e7132f43e9437edfe86bd4d1af6104aa328ba11725ff80130334f1758
2020-08-01 12:12:20.085 [DBG] CORE: Match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538 not swappable: failErr = -4: rejected transaction c5c607b8dbd2867a4e62ecb2e8d8e202e615970622377254dd8b9a1bd71fbf6d: transaction c5c607b8dbd2867a4e62ecb2e8d8e202e615970622377254dd8b9a1bd71fbf6d has 700000000 fee which is above the allowHighFee check threshold amount of 34800000, revoked = false

server:

2020-08-01 12:12:20.072 [DBG] SWAP: handleRedeem: 'redeem' received from c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430 for match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538, order e14f17d23788de4f50c0c12928b4c1b842a262f174c87ddfd86f2c29e6ea6b2d
2020-08-01 12:12:20.072 [DBG] SWAP: step(user=c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430, match=14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538): ready for user c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430 action, status TakerSwapCast, next MakerRedeemed
2020-08-01 12:12:20.075 [DBG] SWAP: processRedeem: valid redemption received at 2020-08-01 03:12:20.075 +0000 UTC from c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430 for match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538, swapStatus TakerSwapCast => MakerRedeemed
2020-08-01 12:12:20.076 [DBG] SWAP: processRedeem: sending 'redeem' ack request to counterparty c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430 for match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538
2020-08-01 12:12:20.077 [DBG] AUTH: Recorded order 533aa78e7132f43e9437edfe86bd4d1af6104aa328ba11725ff80130334f1758 that has finished processing: user=c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430, time=1596251540077, target=<nil>
2020-08-01 12:12:20.645 [DBG] ASSET[btc]: Run: Processing new block 59f69d98116baebf66461986b0fdc060eb75cf6126ba7e90cfbd32da13ad1a1e
2020-08-01 12:12:20.645 [DBG] ASSET[btc]: Notifying 1 btc asset consumers of new block at height 152
2020-08-01 12:12:21.646 [DBG] ASSET[btc]: Run: Processing new block 1f03d7ee0fb5020db4aa99243ee74806618cb915fbba74f1f647ec96c25a0bfe
2020-08-01 12:12:21.646 [DBG] ASSET[btc]: Notifying 1 btc asset consumers of new block at height 153
2020-08-01 12:12:22.710 [DBG] ASSET[dcr]: Run: Processing new block 0009ba9bb077b6190afb3a9a49fe20e75462a7637e4dc4704d226f46bad2a7e1
2020-08-01 12:12:22.710 [DBG] ASSET[dcr]: Notifying 1 dcr asset consumers of new block at height 192
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match d7ffe51507c9b9c588d66c66cb9486632378d78702861059284e978aa3fb5412
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 7e8e7a3727b3b41798192714a3586630b0c89b2475e9f438d27d096a9eb50a61
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 527ad598450a92af2ad12991dfb3071ad0fc19afbd642703dc4998f3b13951ab
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match a974b741950fd6ad920bc19d1c51d483fbc04056aabbb5794c18ed0061e0a4b8
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 6a1788a8b91c2e88ce9ac2efb134cfa849a7c7459b3b93271fa7cbc8ba523b8a
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 139f6865f0b895324cfd770f626d6f70b3de6eb09c6b92e6d8e1b91c1bf508bc
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 64792dbd5cb672e70f9f2ce1fba86a77bf9468d469009ec8033ddf47bedae95e
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match efc05e6be01b39fec7412c89319fedaedd5e4892e3eb8da6efac68040acd476a
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 315b72e7f1c2fae5332d28e0c14a4f63c871060c6e9ec8c2c26ae75c0f5c0218
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 3f8056708d984aef360508127c20fdd62a63c968006fb8b09313cf0d97709335
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 4bce270681e1f7326f3f9d4e523ea3f8638e9fd0e691f4f80e6d54562b4093ec
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match 60e7fc9fc808b7b2fe42f83c0227179b6b79b7ab9127545d56e011465133e43a
2020-08-01 12:12:22.746 [DBG] SWAP: Deleting completed match f1f2941bd4dbbd8098c0e2e67b900fa07ee1409335b5e3979b6828701c4b4613
2020-08-01 12:12:30.219 [TRC] COMM: got pong from 127.0.0.1:48458
2020-08-01 12:13:24.219 [TRC] COMM: got pong from 127.0.0.1:48458
2020-08-01 12:13:24.709 [DBG] SWAP: checkInaction(failMatch): swap 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538 failing (maker fault = false) at MakerRedeemed
2020-08-01 12:13:24.710 [WRN] SWAP: isOrderComplete: untracked order 533aa78e7132f43e9437edfe86bd4d1af6104aa328ba11725ff80130334f1758
2020-08-01 12:13:24.710 [DBG] AUTH: Recorded order e14f17d23788de4f50c0c12928b4c1b842a262f174c87ddfd86f2c29e6ea6b2d that has finished processing: user=c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430, time=1596251604710, target=<nil>
2020-08-01 12:13:24.714 [DBG] AUTH: user c342103ea510eebbf7c3be05b095f8bccf8aea374954fa85011f3a89870b5430 penalized for rule 1
2020-08-01 12:13:24.714 [INF] SWAP: revoke: sending the 'revoke_match' request to each client for match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538
2020-08-01 12:13:24.723 [INF] SWAP: Received revoke ack for match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538, order 533aa78e7132f43e9437edfe86bd4d1af6104aa328ba11725ff80130334f1758
2020-08-01 12:13:24.732 [INF] SWAP: Received revoke ack for match 14e1020a40c629ff699e1754546eff7318344e28ffe03ea53f2915ab92319538, order e14f17d23788de4f50c0c12928b4c1b842a262f174c87ddfd86f2c29e6ea6b2d
2020-08-01 12:14:18.219 [TRC] COMM: got pong from 127.0.0.1:48458

client/core/core.go Outdated Show resolved Hide resolved
client/core/core.go Outdated Show resolved Hide resolved
@chappjc

This comment has been minimized.

@chappjc
Copy link
Member Author

chappjc commented Aug 1, 2020

Yeah, there's DCR fallback fee rate bug when using dexcctl to setup wallets:

2020-07-31 23:24:28.835 [INF] CORE[btc]: Setting up new btc wallet at localhost:20556/wallet/gamma.
2020-07-31 23:24:28.835 [TRC] CORE[btc]: fallback fees set at 100 Satoshis/byte
2020-07-31 23:24:28.835 [INF] CORE: Loaded btc wallet configuration. Deposit address = msno8TvCPFRLMrSjoDXnK3xqmVaiaQWMoE
2020-07-31 23:24:28.835 [TRC] CORE[dcr]: fallback fees set at 2000000 atoms/byte
2020-07-31 23:24:28.835 [INF] CORE[dcr]: Setting up new DCR wallet at 127.0.0.1:19567 with TLS certificate "/home/jon/dextest/dcr/alpha/rpc.cert".

A temporary workaround is to go into the Reconfigure Decred Wallet dialog on the browser and submit with 0.0002, which should be already entered. Doing this sets the fallback fee rate to 20 atoms/byte, where it should be:

[TRC] CORE[dcr]: fallback fees set at 20 atoms/byte

@chappjc
Copy link
Member Author

chappjc commented Aug 1, 2020

The incorrect DCR default fallback fee for non-browser wallet setups should now be fixed in the latest commit: 03b3452

@chappjc
Copy link
Member Author

chappjc commented Aug 4, 2020

@buck54321 Anything to address remaining? I don't have better choices for the coinwaiter timeouts discussed in #565 (comment).

// field being an empty string.
isCancel := t.cancel != nil && msgMatch.Address == ""
if isCancel {
match.setStatus(order.MatchComplete)
Copy link
Member

Choose a reason for hiding this comment

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

Thanks for this. This is the first step needed to fix

// TODO: The trackedTrade.cancel.matches is not being repopulated on

client/core/trade.go Outdated Show resolved Hide resolved
client/core/trade.go Outdated Show resolved Hide resolved
client/core/trade.go Outdated Show resolved Hide resolved
client/db/types.go Show resolved Hide resolved
@chappjc
Copy link
Member Author

chappjc commented Aug 4, 2020

@buck54321 Back to SetFill. I need to manually retest with a restart with a partially filled trade though.

@chappjc
Copy link
Member Author

chappjc commented Aug 4, 2020

Retested and working as expected still:

Partially filled book order;

image

Restart dexc, then fill the rest of it:

image

Fill at 100%.

Also note the one canceled order showing 100% fill as expected with the fill sum computation in negotiate considering the maker cancel match quantity in the fill amount.

Copy link
Member

@buck54321 buck54321 left a comment

Choose a reason for hiding this comment

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

Looks good.

Copy link
Member

@itswisdomagain itswisdomagain left a comment

Choose a reason for hiding this comment

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

First pass. Will have a go again later.

client/comms/wsconn.go Outdated Show resolved Hide resolved
client/comms/wsconn.go Outdated Show resolved Hide resolved
client/comms/wsconn.go Outdated Show resolved Hide resolved
client/comms/wsconn_test.go Outdated Show resolved Hide resolved
client/core/core.go Outdated Show resolved Hide resolved
Comment on lines +2852 to 3043
// Send the match acknowledgments.
// TODO: Consider a "QueueSend" or similar, but do not bail on the matches.
err = dc.Send(resp)
if err != nil {
return err
log.Errorf("Send match response: %v", err)
// dc.addPendingSend(resp) // e.g.
}
Copy link
Member

Choose a reason for hiding this comment

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

Right. This is documented under Potential causes of trade disruptions in #361 which is a little similar to a previously existing issue where failure to send an init or redeem request to the server would cause the trade to go to hell. The latter is fixed with resendPendingRequests and similar stuff can be done for request acks send errors. Can create an issue to track this.

@chappjc chappjc force-pushed the async-client-inhandler branch 2 times, most recently from d335924 to 2f89f24 Compare August 5, 2020 18:14
@chappjc
Copy link
Member Author

chappjc commented Aug 6, 2020

@itswisdomagain Please to note any remaining issues to address in a follow up. I've retested again, and we need the DCR fee rate fix, so I'm going to get this merged now.

chappjc added 3 commits August 6, 2020 09:14
In client/comms.(*wsConn).Send, marshal the Message first so that we
do not send junk to the peer even if it fails to marshal completely,
which WriteJSON does.

Test marshal error with Send/Request, and removal of response handler
in this case with Requst.

Test RequestWithTimeout expiration handler and response handler removal.
Incoming requests and notifications queue the call to the registered
handler function in a dedicated runner a goroutine now to prevent
blocking subsequent reqs/ntfns. If the channel buffer fills, handling
becomes blocking again, as it was before this change.

(*dexConnection).runMatches now starts negotiation of a trades's new
matches in parallel since runMatches>tick>{swap,redeem,refund}Matches
can block for a long time waiting for a response from the server.

In handleMatchRoute, wait briefly before runMatches to reduce the chance
that the server will not have yet saved the match ack sig sent just
prior.  On the server side, processMatchAcks now locks all of the
involved matchTrackers right out of the gates, before processing the
client's acks.  This is still a race, but it cannot be fully resolved
until/unless the client can get an OK/done back from it's own ack
response to the original match requests.  However, resendPendingRequests
will retry failed 'init' requests so this is not a show stopper bug.

Do not try to swap/redeem/refund cancel matches in (*trackedTrade).tick.

Tweak errorSet formatting to reflect a set, and rename ifany to ifAny.

Refine logging in trade.go.

client/{core,comms}: create and use RequestWithTimeout

Add comms.WsConn.RequestWithTimeout, implemented by wsConn.
RequestWithTimeout has a expire/response timeout duration and expire
callback input args.

Add comms.DefaultRequestTimeout for use in vanilla Request, and by
consumers that wish to set an expire function, but no particular timeout.

(*dexConnection).signAndRequest now accepts a timeout duration.

Remove core.txWaitExpiration, which was arbitrary and not coordinated
with the server.  Instead use broadcast timeout in:
- finalizeSwapAction>signAndRequest, where the server waits for an
  unspecified time that could be up to broadcast timeout.
- finalizeRedeemAction>signAndRequest, for the same reasons as above
- processAudit>latencyQ.Wait, since there is no reason to give up sooner
- notifyFee, for the same reason as processAudit.
However, there may be reason to timeout sooner in the init and redeem
requests if the client thinks resending the request might help.

The DefaultRequestTimeout is used in:
- place cancel order request
- place trade order request
- register request
- connect request (authDEX)
- config request (connectDEX)

TODO: If the server responds to init or redeem with an Error payload
with Code TransactionUndiscovered, the client may try to rebroadcast the
transaction that the server couldn't find, specially if the response
comes well in advance of broadcast timeout (penalization time).

server/swap: longer audit request timeout

This should be up to broadcast timeout, but not for the redemption
request where the client does not need to check the coin network.

Also hold the match mtx locked and check that the match isn't revoked
before storing results in processInit and processRedeem.

client/core: store both cancel Matches
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.

client/core: init and redeem requests need to wait much longer for a response
4 participants