loadbot/doge: Order placed with locked coins.

[JoeGruffins]

Running loadbot at https://github.com/decred/dcrdex/pull/1656/commits/a2ad03d399015fc35e80a9ccc7fb66cc1de6292b on the dcr_doge market.

doge placed an order with coins that the server considered locked. Also, the error sent to the client is not specific enough to know the problem without looking at server logs.

The loadbot error:

2022-06-20 17:37:19.334 [CRT] MANTLE:CMPD:SNIPER:0: Trade error (market order, sell = false, qty = 10252800000: new order request with DEX server 127.0.0.1:17273 market dcr_doge failed: rpc error: error code 34: order failed validation

The server error:

2022-06-20 17:37:19.334 [TRC] MKT: Received order 9e0c32d30db91b564a40aa21318351858fc7d8e7029c3c44ce004ff9f9307c32 at 2022-06-20 08:37:19.334 +0000 UTC                                                                                                                         
2022-06-20 17:37:19.334 [DBG] MKT: User placing likely-taker order on market dcr_doge worth 974600760 (dcr units) of 15800000000 allowed. User has 200000000 (dcr units) in 1 active swaps, 0 in epoch taker orders.                                                            
2022-06-20 17:37:19.334 [DBG] MKT: processOrder: Order 9e0c32d30db91b564a40aa21318351858fc7d8e7029c3c44ce004ff9f9307c32 submitted with already-locked coins: [5983b1605ebf439e09898196f467ad85d4b01ca2d281ed6d74159fffd6132c0200000000]                                         
2022-06-20 17:37:19.334 [DBG] MKT: Market failed to SubmitOrder: order failed validation                                                                                                                                                                                        
2022-06-20 17:37:19.334 [DBG] MKT: Error going to user f7f51cabde473c93287e4fecc5f2c1d9183b4b3fce48401ea632ed9f45329b4f: error code 34: order failed validation 

Indeed the client is using the same coin twice. Appears to be a race:

2022-06-20 17:37:19.276 [INF] CORE:CMPD:STACKER:1[doge]: Funding 32.52 doge order with coins [022c13d6ff9f15746ded81d2a21cb0d485ad67f4968189099e43bf5e60b18359:0 bf294df6b081f3e7350e0b41591ce74b2bbc8875f09131207
97e862cadcc1929:1] worth 38.28303492
2022-06-20 17:37:19.277 [INF] CORE:CMPD:SNIPER:0[doge]: Funding 102.528 doge order with coins [022c13d6ff9f15746ded81d2a21cb0d485ad67f4968189099e43bf5e60b18359:0 ed4a578e7af35ca65f3c59f3271d24fa2d3f4049dbecb51d
44ccf5e1d90699d9:0 eefba2189d1063bfa82a4d6292fcb7c5505bbd933e3e53bac69770294b7cfed7:0 7dcf9dbd314124255f417db3d35593ce7490af878a3bec89609fbabbabff2dc2:0 468bc5ce7c96ea00754c5b856388cf449825f524509f54d71227e8540
8181886:0] worth 107.11169056 

The server's log could be encoded better.

Client logs: doge1.txt

[chappjc]

There appears to be multiple Core instances (a STACKER and a SNIPER) using the same dogecoind instance for their wallet. Since they are not the same baseWallet instances, they don't share the same btc.fundingMtx, which for a single instance makes the listunspents -> lockunspent call effectively atomic.

I don't think there's a problem with the client code that's causing this double lock attempt (or with loadbot). It looks like there's an issue with DOGE's ./start-wallet that fails to make a separate wallet, or at least one with separate address keys.

cat > "./start-wallet" <<EOF
#!/usr/bin/env bash

mkdir ${NODES_ROOT}/\$1

printf "rpcuser=user\nrpcpassword=pass\ndatadir=${DELTA_DIR}\ntxindex=1\nregtest=1\nrpcport=\$2\n" > ${NODES_ROOT}/\$1/\$1.conf

${DAEMON} -rpcuser=user -rpcpassword=pass \
-rpcport=\$2 -datadir=${NODES_ROOT}/\$1 -txindex=1 -regtest=1 \
-debug=rpc -debug=net -debug=mempool -debug=walletdb -debug=addrman -debug=mempoolrej \
-whitelist=127.0.0.0/8 -whitelist=::1 \
-port=\$3 -fallbackfee=0.00001 -printtoconsole
EOF
chmod +x "./start-wallet"

The datadir written to the config file doesn't match the datadir used on the command line. I would expect the command line to take precedence, but that still looks off. Maybe ${DELTA_DIR} there needs to be changed to ${NODES_ROOT}/\$1

[chappjc]

Oh, all the loadbot DOGE wallets are just the same, not the ones that are started with start-wallet. I can reproduce the errors and the UTXO is always one from alpha. The rpc port chosen in (*Mantle).createWallet needs to be given to newBotWallet, not just the name.

Fixing...

[chappjc]

With https://github.com/decred/dcrdex/pull/1677, it ran for almost 8hrs with compound and dcr_doge and didn't hit the error in this issue or https://github.com/decred/dcrdex/issues/1674. Without #1677 it would hit it quickly.

[INF] LOADBOT: LoadBot ran for 7h49m25.041109931s, during which time 12602 orders were placed, resulting in 20997 separate matches, a rate of 44.7 matches / minute

It dies because of DCR alpha failing to do a sendtoaddress [ERR] LOADBOT: exec error (dcr) "./alpha": exit status 1: -6: wallet.SendOutputs: insufficient balance:: txauthor.NewUnsignedTransaction. So that's NBD. Although maybe these sends via the scripts should be a little less than full balance in case the trader programs spend some it first.