Add simnet trading tests #432

itswisdomagain · 2020-05-31T21:03:21Z

Resolves #402. Adds

a dcrdex harness that connects to dcr and btc simnet nodes from the dcr, btc harnesses.
a trade_simnet_test suite that connects to a running dcrdex harness to test different trade sequences and results.

The following trade tests are implemented:

successful completions of all matches for an order
trade failure due to no maker swap
trade failure due to no taker swap
trade failure due to no maker redeem

While a primary motivation for adding the simnet trading tests is to test potential trade disruption states and associated trade/fund recovery implementations, this PR does not exhaust all known possible failure sequences. The plan is to add more tests to the suite in subsequent PRs.

2 dcr and 1 btc wallets are added to the respective simnet harnesses to facilitate trade tests whether using the trade_simnet_test or manually. Will follow up with an update to the Simnet Testing wiki with details for using the dcrdex harness to quickly startup a dex server and using the additional wallets for setting up clients for trading.

itswisdomagain · 2020-05-31T21:44:33Z

Sample test logs from running the trade tests using go test -v -tags harness ./client/core:

Test logs

=== RUN   TestTrading                                                                                                                               
2020-06-09 12:36:09.809 [INF] TEST: === SETUP                                                                                                       
2020-06-09 12:36:09.812 [INF] TEST: [client 1] core created                                                                                         
2020-06-09 12:36:10.885 [INF] TEST: [client 1] core initialized                                                                                     
2020-06-09 12:36:10.956 [INF] TEST: [client 1] connected dcr wallet                                                                                 
2020-06-09 12:36:11.143 [INF] TEST: [client 1] connected btc wallet                                                                                 
2020-06-09 12:36:11.397 [INF] TEST: [client 1] connected DEX 127.0.0.1:17273                                                                        
2020-06-09 12:36:11.401 [INF] TEST: [client 1] mined 1 blocks on dcr trading1 for fee payment confirmation                                          
2020-06-09 12:36:11.401 [INF] TEST: [client 1] waiting 10 seconds for fee confirmation notice                                                       
2020-06-09 12:36:11.967 [INF] TEST: [client 1] fee payment confirmed                                                                                
2020-06-09 12:36:11.970 [INF] TEST: [client 2] core created                                                                                         
2020-06-09 12:36:13.043 [INF] TEST: [client 2] core initialized                                                                                     
2020-06-09 12:36:13.136 [INF] TEST: [client 2] connected dcr wallet                                                                                 
2020-06-09 12:36:13.322 [INF] TEST: [client 2] connected btc wallet                                                                                 
2020-06-09 12:36:13.557 [INF] TEST: [client 2] connected DEX 127.0.0.1:17273                                                                        
2020-06-09 12:36:13.591 [INF] TEST: [client 2] mined 1 blocks on dcr trading2 for fee payment confirmation                                          
2020-06-09 12:36:13.591 [INF] TEST: [client 2] waiting 10 seconds for fee confirmation notice                                                       
2020-06-09 12:36:14.132 [INF] TEST: [client 2] fee payment confirmed                                                                                
2020-06-09 12:36:14.132 [INF] TEST: === SETUP COMPLETED                                                                                             
                                                                                                                                                    
=== RUN   TestTrading/no_maker_swap                                                                                                                 
2020-06-09 12:36:19.132 [INF] TEST: [client 1] unlocking wallets                                                                                    
2020-06-09 12:36:19.647 [INF] TEST: [client 1] updating balances                                                                                    
2020-06-09 12:36:19.786 [INF] TEST: [client 2] unlocking wallets                                                                                    
2020-06-09 12:36:20.298 [INF] TEST: [client 2] updating balances                                                                                    
2020-06-09 12:36:20.493 [INF] TEST: [client 1] placed order buying 10.00000000 dcr at 0.00010000 btc/dcr (b39844bd)                                 
2020-06-09 12:36:20.568 [INF] TEST: [client 2] placed order selling 10.00000000 dcr at 0.00010000 btc/dcr (1929253f)                                
2020-06-09 12:36:20.568 [INF] TEST: [client 1] locking wallets                                                                                      
2020-06-09 12:36:21.076 [INF] TEST: [client 2] locking wallets                                                                                      
2020-06-09 12:36:21.586 [INF] TEST: [client 2] waiting for matches on order 1929253f                                                                
2020-06-09 12:36:21.586 [INF] TEST: [client 1] waiting for matches on order b39844bd                                                                
2020-06-09 12:36:24.024 [INF] TEST: [client 2] 1 match(es) received for order 1929253f                                                              
2020-06-09 12:36:24.025 [INF] TEST: [client 2] Taker on match 0b728e39, amount 10.00000000 dcr                                                      
2020-06-09 12:36:24.025 [INF] TEST: [client 1] 1 match(es) received for order b39844bd                                                              
2020-06-09 12:36:24.025 [INF] TEST: [client 1] Maker on match 0b728e39, amount 10.00000000 dcr                                                      
2020-06-09 12:36:24.025 [INF] TEST: Trades ended at NewlyMatched.                                                                                   
2020-06-09 12:36:24.034 [ERR] CORE: notify: |ERROR| (order) Swap error - Error encountered sending a swap output(s) worth 0.00100000 btc on order b39844bd - Order: b39844bd203143c5a29269dbdb39ada6c70d8b121c11120037a365195070bb74                                                                    
2020-06-09 12:36:24.034 [ERR] CORE: 127.0.0.1:17273 tick: swapMatches: swapMatches order b39844bd203143c5a29269dbdb39ada6c70d8b121c11120037a365195070bb74 - error sending swap transaction: signing error: tx signing error: rawrequest error: -13: Error: Please enter the wallet passphrase with walletpassphrase first.                                                                                                                                  
2020-06-09 12:36:25.026 [INF] TEST: [client 1] updating balances                                                                                    
2020-06-09 12:36:25.034 [INF] TEST: [client 1] dcr balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000                        
2020-06-09 12:36:25.034 [INF] TEST: [client 1] btc balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000                        
2020-06-09 12:36:25.034 [INF] TEST: [client 2] updating balances                                                                                    
2020-06-09 12:36:25.044 [INF] TEST: [client 2] dcr balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000
2020-06-09 12:36:25.044 [INF] TEST: [client 2] btc balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000

=== RUN   TestTrading/no_taker_swap
2020-06-09 12:36:30.044 [INF] TEST: [client 1] unlocking wallets
2020-06-09 12:36:30.553 [INF] TEST: [client 1] updating balances
2020-06-09 12:36:30.563 [INF] TEST: [client 2] unlocking wallets
2020-06-09 12:36:31.073 [INF] TEST: [client 2] updating balances
2020-06-09 12:36:31.259 [INF] TEST: [client 1] placed order selling 8.00000000 dcr at 0.00020000 btc/dcr (2c819b9d)
2020-06-09 12:36:31.323 [INF] TEST: [client 2] placed order buying 8.00000000 dcr at 0.00020000 btc/dcr (18548ad3)
2020-06-09 12:36:31.324 [INF] TEST: [client 2] waiting for matches on order 18548ad3
2020-06-09 12:36:31.324 [INF] TEST: [client 1] waiting for matches on order 2c819b9d
2020-06-09 12:36:36.013 [INF] TEST: [client 2] 1 match(es) received for order 18548ad3
2020-06-09 12:36:36.013 [INF] TEST: [client 2] Taker on match 6e596f18, amount 8.00000000 dcr
2020-06-09 12:36:36.022 [INF] TEST: [client 1] 1 match(es) received for order 2c819b9d
2020-06-09 12:36:36.022 [INF] TEST: [client 1] Maker on match 6e596f18, amount 8.00000000 dcr
2020-06-09 12:36:36.035 [INF] TEST: [client 2] NOW =====> MakerSwapCast
2020-06-09 12:36:36.040 [INF] TEST: [client 1] NOW =====> MakerSwapCast
2020-06-09 12:36:37.044 [INF] TEST: [client 1] Mined 1 blocks for Maker's swap, match 6e596f18
2020-06-09 12:36:37.044 [INF] TEST: [client 1] updated dcr balance diff with -8.000000
2020-06-09 12:36:37.044 [INF] TEST: Trades ended at MakerSwapCast.
2020-06-09 12:36:38.044 [INF] TEST: [client 1] updating balances
2020-06-09 12:36:38.053 [INF] TEST: [client 1] dcr balance change -8.00002500 is in expected range of -9.00000000 - -8.00000000
2020-06-09 12:36:38.053 [INF] TEST: [client 1] btc balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000
2020-06-09 12:36:38.053 [INF] TEST: [client 2] updating balances
2020-06-09 12:36:38.061 [INF] TEST: [client 2] dcr balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000
2020-06-09 12:36:38.061 [INF] TEST: [client 2] btc balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000

=== RUN   TestTrading/no_maker_redeem
2020-06-09 12:36:43.061 [INF] TEST: [client 1] unlocking wallets
2020-06-09 12:36:43.578 [INF] TEST: [client 1] updating balances
2020-06-09 12:36:43.588 [INF] TEST: [client 2] unlocking wallets
2020-06-09 12:36:44.102 [INF] TEST: [client 2] updating balances
2020-06-09 12:36:44.206 [INF] TEST: [client 1] placed order selling 5.00000000 dcr at 0.00025000 btc/dcr (3797134a)
2020-06-09 12:36:44.288 [INF] TEST: [client 2] placed order buying 5.00000000 dcr at 0.00025000 btc/dcr (06c0d82f)
2020-06-09 12:36:44.288 [INF] TEST: [client 2] waiting for matches on order 06c0d82f
2020-06-09 12:36:44.288 [INF] TEST: [client 1] waiting for matches on order 3797134a
2020-06-09 12:36:48.013 [INF] TEST: [client 1] 1 match(es) received for order 3797134a
2020-06-09 12:36:48.013 [INF] TEST: [client 1] Taker on match 33cfc926, amount 5.00000000 dcr
2020-06-09 12:36:48.017 [INF] TEST: [client 2] 1 match(es) received for order 06c0d82f
2020-06-09 12:36:48.017 [INF] TEST: [client 2] Maker on match 33cfc926, amount 5.00000000 dcr
2020-06-09 12:36:48.041 [INF] TEST: [client 2] NOW =====> MakerSwapCast
2020-06-09 12:36:48.045 [INF] TEST: [client 1] NOW =====> MakerSwapCast
2020-06-09 12:36:49.046 [INF] TEST: [client 2] Mined 1 blocks for Maker's swap, match 33cfc926
2020-06-09 12:36:49.046 [INF] TEST: [client 2] updated btc balance diff with -0.001250
2020-06-09 12:36:49.168 [INF] TEST: [client 2] NOW =====> TakerSwapCast
2020-06-09 12:36:49.170 [INF] TEST: [client 1] NOW =====> TakerSwapCast
2020-06-09 12:36:50.178 [INF] TEST: [client 1] Mined 1 blocks for Taker's swap, match 33cfc926
2020-06-09 12:36:50.178 [INF] TEST: [client 1] updated dcr balance diff with -5.000000
2020-06-09 12:36:50.178 [INF] TEST: Trades ended at TakerSwapCast.
2020-06-09 12:36:51.178 [INF] TEST: [client 1] updating balances
2020-06-09 12:36:51.187 [INF] TEST: [client 1] dcr balance change -5.00002490 is in expected range of -6.00000000 - -5.00000000
2020-06-09 12:36:51.187 [INF] TEST: [client 1] btc balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000
2020-06-09 12:36:51.187 [INF] TEST: [client 2] updating balances
2020-06-09 12:36:51.195 [INF] TEST: [client 2] dcr balance change 0.00000000 is in expected range of 0.00000000 - 0.00000000
2020-06-09 12:36:51.195 [INF] TEST: [client 2] btc balance change -0.00147300 is in expected range of -1.00125000 - -0.00125000

=== RUN   TestTrading/success
2020-06-09 12:36:56.196 [INF] TEST: [client 1] unlocking wallets
2020-06-09 12:36:56.708 [INF] TEST: [client 1] updating balances
2020-06-09 12:36:56.720 [INF] TEST: [client 2] unlocking wallets
2020-06-09 12:36:57.236 [INF] TEST: [client 2] updating balances
2020-06-09 12:36:57.325 [INF] TEST: [client 1] placed order selling 12.00000000 dcr at 0.00015000 btc/dcr (231d8dda)
2020-06-09 12:36:57.419 [INF] TEST: [client 2] placed order buying 12.00000000 dcr at 0.00015000 btc/dcr (84efc936)
2020-06-09 12:36:57.419 [INF] TEST: [client 2] waiting for matches on order 84efc936
2020-06-09 12:36:57.419 [INF] TEST: [client 1] waiting for matches on order 231d8dda
2020-06-09 12:37:00.012 [INF] TEST: [client 2] 1 match(es) received for order 84efc936
2020-06-09 12:37:00.012 [INF] TEST: [client 2] Taker on match 6717e05c, amount 12.00000000 dcr
2020-06-09 12:37:00.012 [INF] TEST: [client 1] 1 match(es) received for order 231d8dda
2020-06-09 12:37:00.013 [INF] TEST: [client 1] Maker on match 6717e05c, amount 12.00000000 dcr
2020-06-09 12:37:00.042 [INF] TEST: [client 1] NOW =====> MakerSwapCast
2020-06-09 12:37:00.046 [INF] TEST: [client 2] NOW =====> MakerSwapCast
2020-06-09 12:37:01.047 [INF] TEST: [client 1] Mined 1 blocks for Maker's swap, match 6717e05c
2020-06-09 12:37:01.047 [INF] TEST: [client 1] updated dcr balance diff with -12.000000
2020-06-09 12:37:02.166 [INF] TEST: [client 2] NOW =====> TakerSwapCast
2020-06-09 12:37:03.174 [INF] TEST: [client 2] Mined 1 blocks for Taker's swap, match 6717e05c
2020-06-09 12:37:03.174 [INF] TEST: [client 2] updated btc balance diff with -0.001800
2020-06-09 12:37:04.819 [INF] TEST: [client 1] NOW =====> TakerSwapCast
2020-06-09 12:37:09.619 [INF] TEST: [client 2] NOW =====> MakerRedeemed
2020-06-09 12:37:09.619 [INF] TEST: [client 1] NOW =====> MakerRedeemed
2020-06-09 12:37:09.632 [INF] TEST: [client 2] NOW =====> MatchComplete
2020-06-09 12:37:10.626 [INF] TEST: [client 1] Mined 1 blocks for Maker's redeem, match 6717e05c
2020-06-09 12:37:10.626 [INF] TEST: [client 1] updated btc balance diff with +0.001800
2020-06-09 12:37:10.626 [INF] TEST: [client 1] NOW =====> MatchComplete
2020-06-09 12:37:10.638 [INF] TEST: [client 2] Mined 1 blocks for Taker's redeem, match 6717e05c
2020-06-09 12:37:10.638 [INF] TEST: [client 2] updated dcr balance diff with +12.000000
2020-06-09 12:37:10.638 [INF] TEST: Trades ended at MatchComplete.
2020-06-09 12:37:11.638 [INF] TEST: [client 1] updating balances
2020-06-09 12:37:11.651 [INF] TEST: [client 1] dcr balance change -12.00002500 is in expected range of -13.00000000 - -12.00000000
2020-06-09 12:37:11.651 [INF] TEST: [client 1] btc balance change 0.00147800 is in expected range of -0.99820000 - 0.00180000
2020-06-09 12:37:11.652 [INF] TEST: [client 2] updating balances
2020-06-09 12:37:11.661 [INF] TEST: [client 2] dcr balance change 11.99996510 is in expected range of 11.00000000 - 12.00000000
2020-06-09 12:37:11.662 [INF] TEST: [client 2] btc balance change -0.00202300 is in expected range of -1.00180000 - -0.00180000
--- PASS: TestTrading (61.85s)
    --- PASS: TestTrading/no_maker_swap (5.91s)
    --- PASS: TestTrading/no_taker_swap (8.02s)
    --- PASS: TestTrading/no_maker_redeem (8.13s)
    --- PASS: TestTrading/success (15.47s)
PASS
ok      decred.org/dcrdex/client/core   61.968s

client/core/trade.go

dex/testing/btc/harness.sh

itswisdomagain · 2020-06-09T14:29:01Z

I was hoping to add test for the recently merged refund recovery scenarios but that will have to wait for #438 as 1 key factor determining refundability is the swap locktimes.

If that goes in first, I'll update this PR with the refund recovery test cases. Otherwise, that will come in a subsequent PR.

chappjc · 2020-06-09T20:22:09Z

PR #438 is in if you want to update for the refund/find-redeem recovery scenarios.

JoeGruffins

Most of my test attempts ended at trying to pay the fee. over 90%

failure log

[joe@hyrule dcrdex]$ go test -v -tags harness ./client/core
=== RUN   TestTrading
2020-06-10 16:58:44.336 [INF] TEST: === SETUP
2020-06-10 16:58:44.336 [INF] TEST: [client 1] core created
2020-06-10 16:58:45.368 [INF] TEST: [client 1] core initialized
2020-06-10 16:58:45.409 [INF] TEST: [client 1] connected dcr wallet
2020-06-10 16:58:45.555 [INF] TEST: [client 1] connected btc wallet
2020-06-10 16:58:45.785 [ERR] CORE: Error getting confirmations for 334eb3e2aaa5dc7c7db51e329c5aa02537d3186813f88edbf5b81bba37f1110100000000: -5: no information for transaction
2020-06-10 16:58:45.785 [INF] TEST: [client 1] connected DEX 127.0.0.1:17273
2020-06-10 16:58:45.792 [INF] TEST: [client 1] mined 1 blocks on dcr trading1 for fee payment confirmation
2020-06-10 16:58:45.792 [INF] TEST: [client 1] waiting 5 seconds for fee confirmation notice
    TestTrading: trade_simnet_test.go:223: error starting clients: fee payment not confirmed after 5 seconds
--- FAIL: TestTrading (6.47s)
FAIL
FAIL    decred.org/dcrdex/client/core   6.511s
FAIL
[joe@hyrule dcrdex]$ go test -v -tags harness ./client/core
=== RUN   TestTrading
2020-06-10 16:59:07.141 [INF] TEST: === SETUP
2020-06-10 16:59:07.141 [INF] TEST: [client 1] core created
2020-06-10 16:59:08.175 [INF] TEST: [client 1] core initialized
2020-06-10 16:59:08.216 [INF] TEST: [client 1] connected dcr wallet
2020-06-10 16:59:08.339 [INF] TEST: [client 1] connected btc wallet
2020-06-10 16:59:08.502 [INF] TEST: [client 1] connected DEX 127.0.0.1:17273
2020-06-10 16:59:08.509 [INF] TEST: [client 1] mined 1 blocks on dcr trading1 for fee payment confirmation
2020-06-10 16:59:08.509 [INF] TEST: [client 1] waiting 5 seconds for fee confirmation notice
2020-06-10 16:59:09.219 [INF] TEST: [client 1] fee payment confirmed
2020-06-10 16:59:09.219 [INF] TEST: [client 2] core created
2020-06-10 16:59:10.254 [INF] TEST: [client 2] core initialized
2020-06-10 16:59:10.285 [INF] TEST: [client 2] connected dcr wallet
2020-06-10 16:59:10.435 [INF] TEST: [client 2] connected btc wallet
2020-06-10 16:59:10.582 [ERR] CORE: Error getting confirmations for e0b87e7949ffd158c74f0bcdc920a572fe0fe659aa82249051922eaa77bfbb0700000000: -5: no information for transaction
2020-06-10 16:59:10.582 [INF] TEST: [client 2] connected DEX 127.0.0.1:17273
2020-06-10 16:59:10.590 [INF] TEST: [client 2] mined 1 blocks on dcr trading2 for fee payment confirmation
2020-06-10 16:59:10.590 [INF] TEST: [client 2] waiting 5 seconds for fee confirmation notice
    TestTrading: trade_simnet_test.go:223: error starting clients: fee payment not confirmed after 5 seconds
--- FAIL: TestTrading (8.46s)
FAIL
FAIL    decred.org/dcrdex/client/core   8.532s
FAIL

The --race flag seems to give it the time it need to get the fee paid for some reason. But there are a lot of races shown.

races

=== RUN   TestTrading
2020-06-10 17:29:17.300 [INF] TEST: === SETUP
2020-06-10 17:29:17.301 [INF] TEST: [client 1] core created
2020-06-10 17:29:18.404 [INF] TEST: [client 1] core initialized
2020-06-10 17:29:18.488 [INF] TEST: [client 1] connected dcr wallet
2020-06-10 17:29:18.676 [INF] TEST: [client 1] connected btc wallet
2020-06-10 17:29:19.386 [INF] TEST: [client 1] connected DEX 127.0.0.1:17273
2020-06-10 17:29:19.389 [INF] TEST: [client 1] mined 1 blocks on dcr trading1 for fee payment confirmation
2020-06-10 17:29:19.389 [INF] TEST: [client 1] waiting 5 seconds for fee confirmation notice
2020-06-10 17:29:19.504 [INF] TEST: [client 1] fee payment confirmed
2020-06-10 17:29:19.505 [INF] TEST: [client 2] core created
2020-06-10 17:29:20.607 [INF] TEST: [client 2] core initialized
2020-06-10 17:29:20.723 [INF] TEST: [client 2] connected dcr wallet
2020-06-10 17:29:20.915 [INF] TEST: [client 2] connected btc wallet
2020-06-10 17:29:21.274 [INF] TEST: [client 2] connected DEX 127.0.0.1:17273
2020-06-10 17:29:21.281 [INF] TEST: [client 2] mined 1 blocks on dcr trading2 for fee payment confirmation
2020-06-10 17:29:21.281 [INF] TEST: [client 2] waiting 5 seconds for fee confirmation notice
2020-06-10 17:29:21.752 [INF] TEST: [client 2] fee payment confirmed
2020-06-10 17:29:21.752 [INF] TEST: === SETUP COMPLETED

=== RUN   TestTrading/success
2020-06-10 17:29:21.753 [INF] TEST: [client 1] unlocking wallets
2020-06-10 17:29:22.264 [INF] TEST: [client 1] updating balances
2020-06-10 17:29:22.385 [INF] TEST: [client 2] unlocking wallets
2020-06-10 17:29:22.897 [INF] TEST: [client 2] updating balances
2020-06-10 17:29:23.032 [INF] TEST: [client 1] placed order selling 12.00000000 dcr at 0.00015000 btc/dcr (ab34b75a)
2020-06-10 17:29:23.145 [INF] TEST: [client 2] placed order buying 12.00000000 dcr at 0.00015000 btc/dcr (cd2ca6e4)
2020-06-10 17:29:23.145 [INF] TEST: [client 1] waiting for matches on order ab34b75a
2020-06-10 17:29:23.145 [INF] TEST: [client 2] waiting for matches on order cd2ca6e4
2020-06-10 17:29:24.025 [INF] TEST: [client 1] 1 match(es) received for order ab34b75a
2020-06-10 17:29:24.026 [INF] TEST: [client 1] Taker on match 1ed97794, amount 12.00000000 dcr
2020-06-10 17:29:24.049 [INF] TEST: [client 2] 1 match(es) received for order cd2ca6e4
2020-06-10 17:29:24.049 [INF] TEST: [client 2] Maker on match 1ed97794, amount 12.00000000 dcr
==================
WARNING: DATA RACE
Write at 0x00c000ec4060 by goroutine 62:
  decred.org/dcrdex/client/core.(*matchTracker).setStatus()
      /home/joe/git/dcrdex/client/core/trade.go:49 +0x2c91
  decred.org/dcrdex/client/core.(*trackedTrade).swapMatches()
      /home/joe/git/dcrdex/client/core/trade.go:718 +0x2c5d
  decred.org/dcrdex/client/core.(*trackedTrade).tick()
      /home/joe/git/dcrdex/client/core/trade.go:562 +0x18fe
  decred.org/dcrdex/client/core.(*trackedTrade).negotiate()
      /home/joe/git/dcrdex/client/core/trade.go:377 +0x15f5
  decred.org/dcrdex/client/core.(*dexConnection).runMatches()
      /home/joe/git/dcrdex/client/core/core.go:300 +0x1f2
  decred.org/dcrdex/client/core.handleMatchRoute()
      /home/joe/git/dcrdex/client/core/core.go:2591 +0x391
  decred.org/dcrdex/client/core.(*Core).listen()
      /home/joe/git/dcrdex/client/core/core.go:2505 +0x4d0

Previous read at 0x00c000ec4060 by goroutine 97:
  decred.org/dcrdex/client/core.monitorTradeForTestOrder.func3()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:451 +0x1b1
  decred.org/dcrdex/client/core.tryUntil()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:531 +0x1e3
  decred.org/dcrdex/client/core.monitorTradeForTestOrder()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:448 +0x1549
  decred.org/dcrdex/client/core.simpleTradeTest.func2()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:332 +0xb8
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:57 +0x85

Goroutine 62 (running) created at:
  decred.org/dcrdex/client/core.(*Core).connectDEX()
      /home/joe/git/dcrdex/client/core/core.go:2335 +0x1cb8
  decred.org/dcrdex/client/core.(*Core).Register()
      /home/joe/git/dcrdex/client/core/core.go:1010 +0x3b5
  decred.org/dcrdex/client/core.startClients()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:153 +0xfd8
  decred.org/dcrdex/client/core.TestTrading()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:221 +0x436
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb

Goroutine 97 (running) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:54 +0x73
  decred.org/dcrdex/client/core.simpleTradeTest()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:331 +0x937
  decred.org/dcrdex/client/core.testTradeSuccess()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:248 +0xb6
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb
==================
==================
WARNING: DATA RACE
Read at 0x00c000ec4060 by goroutine 97:
  decred.org/dcrdex/client/core.monitorTradeForTestOrder.func3()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:451 +0x1b1
  decred.org/dcrdex/client/core.tryUntil()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:531 +0x1e3
  decred.org/dcrdex/client/core.monitorTradeForTestOrder()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:448 +0x1549
  decred.org/dcrdex/client/core.simpleTradeTest.func2()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:332 +0xb8
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:57 +0x85

Previous write at 0x00c000ec4060 by goroutine 62:
  decred.org/dcrdex/client/core.(*matchTracker).setStatus()
      /home/joe/git/dcrdex/client/core/trade.go:49 +0x2c91
  decred.org/dcrdex/client/core.(*trackedTrade).swapMatches()
      /home/joe/git/dcrdex/client/core/trade.go:718 +0x2c5d
  decred.org/dcrdex/client/core.(*trackedTrade).tick()
      /home/joe/git/dcrdex/client/core/trade.go:562 +0x18fe
  decred.org/dcrdex/client/core.(*trackedTrade).negotiate()
      /home/joe/git/dcrdex/client/core/trade.go:377 +0x15f5
  decred.org/dcrdex/client/core.(*dexConnection).runMatches()
      /home/joe/git/dcrdex/client/core/core.go:300 +0x1f2
  decred.org/dcrdex/client/core.handleMatchRoute()
      /home/joe/git/dcrdex/client/core/core.go:2591 +0x391
  decred.org/dcrdex/client/core.(*Core).listen()
      /home/joe/git/dcrdex/client/core/core.go:2505 +0x4d0

Goroutine 97 (running) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:54 +0x73
  decred.org/dcrdex/client/core.simpleTradeTest()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:331 +0x937
  decred.org/dcrdex/client/core.testTradeSuccess()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:248 +0xb6
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb

Goroutine 62 (running) created at:
  decred.org/dcrdex/client/core.(*Core).connectDEX()
      /home/joe/git/dcrdex/client/core/core.go:2335 +0x1cb8
  decred.org/dcrdex/client/core.(*Core).Register()
      /home/joe/git/dcrdex/client/core/core.go:1010 +0x3b5
  decred.org/dcrdex/client/core.startClients()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:153 +0xfd8
  decred.org/dcrdex/client/core.TestTrading()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:221 +0x436
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb
==================
2020-06-10 17:29:24.099 [INF] TEST: [client 2] NOW =====> MakerSwapCast
2020-06-10 17:29:25.108 [INF] TEST: [client 2] Mined 1 blocks for Maker's swap, match 1ed97794
2020-06-10 17:29:25.108 [INF] TEST: [client 2] updated btc balance diff with -0.001800
==================
WARNING: DATA RACE
Write at 0x00c004736140 by goroutine 76:
  decred.org/dcrdex/client/core.(*matchTracker).setStatus()
      /home/joe/git/dcrdex/client/core/trade.go:49 +0x24e2
  decred.org/dcrdex/client/core.(*trackedTrade).processAudit()
      /home/joe/git/dcrdex/client/core/trade.go:966 +0x24ae
  decred.org/dcrdex/client/core.handleAuditRoute()
      /home/joe/git/dcrdex/client/core/core.go:2608 +0x2ae
  decred.org/dcrdex/client/core.(*Core).listen()
      /home/joe/git/dcrdex/client/core/core.go:2505 +0x4d0

Previous read at 0x00c004736140 by goroutine 93:
  decred.org/dcrdex/client/core.monitorTradeForTestOrder.func3()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:451 +0x1b1
  decred.org/dcrdex/client/core.tryUntil()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:531 +0x1e3
  decred.org/dcrdex/client/core.monitorTradeForTestOrder()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:448 +0x1549
  decred.org/dcrdex/client/core.simpleTradeTest.func1()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:329 +0xb8
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:57 +0x85

Goroutine 76 (running) created at:
  decred.org/dcrdex/client/core.(*Core).connectDEX()
      /home/joe/git/dcrdex/client/core/core.go:2335 +0x1cb8
  decred.org/dcrdex/client/core.(*Core).Register()
      /home/joe/git/dcrdex/client/core/core.go:1010 +0x3b5
  decred.org/dcrdex/client/core.startClients()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:153 +0xfd8
  decred.org/dcrdex/client/core.TestTrading()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:221 +0x436
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb

Goroutine 93 (running) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:54 +0x73
  decred.org/dcrdex/client/core.simpleTradeTest()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:328 +0x853
  decred.org/dcrdex/client/core.testTradeSuccess()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:248 +0xb6
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb
==================
==================
WARNING: DATA RACE
Read at 0x00c004736140 by goroutine 93:
  decred.org/dcrdex/client/core.monitorTradeForTestOrder.func3()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:451 +0x1b1
  decred.org/dcrdex/client/core.tryUntil()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:531 +0x1e3
  decred.org/dcrdex/client/core.monitorTradeForTestOrder()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:448 +0x1549
  decred.org/dcrdex/client/core.simpleTradeTest.func1()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:329 +0xb8
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:57 +0x85

Previous write at 0x00c004736140 by goroutine 76:
  decred.org/dcrdex/client/core.(*matchTracker).setStatus()
      /home/joe/git/dcrdex/client/core/trade.go:49 +0x24e2
  decred.org/dcrdex/client/core.(*trackedTrade).processAudit()
      /home/joe/git/dcrdex/client/core/trade.go:966 +0x24ae
  decred.org/dcrdex/client/core.handleAuditRoute()
      /home/joe/git/dcrdex/client/core/core.go:2608 +0x2ae
  decred.org/dcrdex/client/core.(*Core).listen()
      /home/joe/git/dcrdex/client/core/core.go:2505 +0x4d0

Goroutine 93 (running) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:54 +0x73
  decred.org/dcrdex/client/core.simpleTradeTest()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:328 +0x853
  decred.org/dcrdex/client/core.testTradeSuccess()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:248 +0xb6
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb

Goroutine 76 (running) created at:
  decred.org/dcrdex/client/core.(*Core).connectDEX()
      /home/joe/git/dcrdex/client/core/core.go:2335 +0x1cb8
  decred.org/dcrdex/client/core.(*Core).Register()
      /home/joe/git/dcrdex/client/core/core.go:1010 +0x3b5
  decred.org/dcrdex/client/core.startClients()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:153 +0xfd8
  decred.org/dcrdex/client/core.TestTrading()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:221 +0x436
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb
==================
2020-06-10 17:29:27.304 [INF] TEST: [client 1] NOW =====> MakerSwapCast
2020-06-10 17:29:27.325 [INF] TEST: [client 2] NOW =====> TakerSwapCast
2020-06-10 17:29:27.347 [INF] TEST: [client 1] NOW =====> TakerSwapCast
2020-06-10 17:29:28.355 [INF] TEST: [client 1] Mined 1 blocks for Taker's swap, match 1ed97794
2020-06-10 17:29:28.355 [INF] TEST: [client 1] updated dcr balance diff with -12.000000
2020-06-10 17:29:28.743 [INF] TEST: [client 1] NOW =====> MakerRedeemed
2020-06-10 17:29:28.745 [INF] TEST: [client 2] NOW =====> MakerRedeemed
2020-06-10 17:29:29.753 [INF] TEST: [client 2] Mined 1 blocks for Maker's redeem, match 1ed97794
2020-06-10 17:29:29.753 [INF] TEST: [client 2] updated dcr balance diff with +12.000000
2020-06-10 17:29:36.864 [INF] TEST: [client 2] NOW =====> MatchComplete
2020-06-10 17:29:36.864 [INF] TEST: [client 1] NOW =====> MatchComplete
==================
WARNING: DATA RACE
Read at 0x00c000bec2b0 by goroutine 90:
  decred.org/dcrdex/client/core.(*trackedTrade).isSwappable()
      /home/joe/git/dcrdex/client/core/trade.go:406 +0x56
  decred.org/dcrdex/client/core.(*trackedTrade).tick()
      /home/joe/git/dcrdex/client/core/trade.go:536 +0x451
  decred.org/dcrdex/client/core.(*dexConnection).tickAsset()
      /home/joe/git/dcrdex/client/core/core.go:340 +0x1ea
  decred.org/dcrdex/client/core.(*Core).tipChange()
      /home/joe/git/dcrdex/client/core/core.go:2683 +0x41b
  decred.org/dcrdex/client/core.(*Core).loadWallet.func1()
      /home/joe/git/dcrdex/client/core/core.go:854 +0x7e
  decred.org/dcrdex/client/asset/dcr.(*ExchangeWallet).monitorBlocks()
      /home/joe/git/dcrdex/client/asset/dcr/dcr.go:1607 +0x44b
  decred.org/dcrdex/client/asset/dcr.(*ExchangeWallet).Connect.func1()
      /home/joe/git/dcrdex/client/asset/dcr/dcr.go:356 +0x89

Previous write at 0x00c000bec2b0 by goroutine 93:
  decred.org/dcrdex/client/core.monitorTradeForTestOrder.func3()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:454 +0x10a1
  decred.org/dcrdex/client/core.tryUntil()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:531 +0x1e3
  decred.org/dcrdex/client/core.monitorTradeForTestOrder()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:448 +0x1549
  decred.org/dcrdex/client/core.simpleTradeTest.func1()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:329 +0xb8
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:57 +0x85

Goroutine 90 (running) created at:
  decred.org/dcrdex/client/asset/dcr.(*ExchangeWallet).Connect()
      /home/joe/git/dcrdex/client/asset/dcr/dcr.go:354 +0x406
  decred.org/dcrdex/dex.(*ConnectionMaster).Connect()
      /home/joe/git/dcrdex/dex/runner.go:100 +0xc1
  decred.org/dcrdex/client/core.(*xcWallet).Connect()
      /home/joe/git/dcrdex/client/core/wallet.go:100 +0x68
  decred.org/dcrdex/client/core.(*Core).CreateWallet()
      /home/joe/git/dcrdex/client/core/core.go:790 +0x946
  decred.org/dcrdex/client/core.startClients()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:125 +0x860
  decred.org/dcrdex/client/core.TestTrading()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:221 +0x436
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb

Goroutine 93 (running) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:54 +0x73
  decred.org/dcrdex/client/core.simpleTradeTest()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:328 +0x853
  decred.org/dcrdex/client/core.testTradeSuccess()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:248 +0xb6
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb
==================
==================
WARNING: DATA RACE
Read at 0x00c0057105b0 by goroutine 62:
  decred.org/dcrdex/client/core.(*trackedTrade).isSwappable()
      /home/joe/git/dcrdex/client/core/trade.go:406 +0x56
  decred.org/dcrdex/client/core.(*trackedTrade).tick()
      /home/joe/git/dcrdex/client/core/trade.go:536 +0x451
  decred.org/dcrdex/client/core.handleRedemptionRoute()
      /home/joe/git/dcrdex/client/core/core.go:2638 +0x2d2
  decred.org/dcrdex/client/core.(*Core).listen()
      /home/joe/git/dcrdex/client/core/core.go:2505 +0x4d0

Previous write at 0x00c0057105b0 by goroutine 97:
  decred.org/dcrdex/client/core.monitorTradeForTestOrder.func3()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:454 +0x10a1
  decred.org/dcrdex/client/core.tryUntil()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:531 +0x1e3
  decred.org/dcrdex/client/core.monitorTradeForTestOrder()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:448 +0x1549
  decred.org/dcrdex/client/core.simpleTradeTest.func2()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:332 +0xb8
  golang.org/x/sync/errgroup.(*Group).Go.func1()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:57 +0x85

Goroutine 62 (running) created at:
  decred.org/dcrdex/client/core.(*Core).connectDEX()
      /home/joe/git/dcrdex/client/core/core.go:2335 +0x1cb8
  decred.org/dcrdex/client/core.(*Core).Register()
      /home/joe/git/dcrdex/client/core/core.go:1010 +0x3b5
  decred.org/dcrdex/client/core.startClients()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:153 +0xfd8
  decred.org/dcrdex/client/core.TestTrading()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:221 +0x436
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb

Goroutine 97 (finished) created at:
  golang.org/x/sync/errgroup.(*Group).Go()
      /home/joe/go/pkg/mod/golang.org/x/[email protected]/errgroup/errgroup.go:54 +0x73
  decred.org/dcrdex/client/core.simpleTradeTest()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:331 +0x937
  decred.org/dcrdex/client/core.testTradeSuccess()
      /home/joe/git/dcrdex/client/core/trade_simnet_test.go:248 +0xb6
  testing.tRunner()
      /home/joe/.local/go/src/testing/testing.go:991 +0x1eb
==================
2020-06-10 17:29:37.872 [INF] TEST: [client 1] Mined 1 blocks for Taker's redeem, match 1ed97794
2020-06-10 17:29:37.872 [INF] TEST: [client 1] updated btc balance diff with +0.001800
2020-06-10 17:29:37.872 [INF] TEST: Trades ended at MatchComplete.
2020-06-10 17:29:38.872 [INF] TEST: [client 1] updating balances
2020-06-10 17:29:38.890 [INF] TEST: [client 1] dcr balance change -12.00002500 is in expected range of -13.00000000 - -12.00000000
2020-06-10 17:29:38.890 [INF] TEST: [client 1] btc balance change 0.00147800 is in expected range of -0.99820000 - 0.00180000
2020-06-10 17:29:38.890 [INF] TEST: [client 2] updating balances
2020-06-10 17:29:38.904 [INF] TEST: [client 2] dcr balance change 11.99996510 is in expected range of 11.00000000 - 12.00000000
2020-06-10 17:29:38.904 [INF] TEST: [client 2] btc balance change -0.00202300 is in expected range of -1.00180000 - -0.00180000
    TestTrading/success: testing.go:906: race detected during execution of test
    TestTrading: testing.go:906: race detected during execution of test
--- FAIL: TestTrading (21.60s)
    --- FAIL: TestTrading/success (17.15s)
2020-06-10 17:29:38.905 [ERR] CORE: refreshUser: error checking if app is initialized: database not open
2020-06-10 17:29:38.906 [ERR] CORE: refreshUser: error checking if app is initialized: database not open
    : testing.go:906: race detected during execution of test
FAIL
FAIL	decred.org/dcrdex/client/core	22.623s
FAIL

go.mod

dex/testing/dcrdex/harness.sh

dex/testing/dcr/harness.sh

dex/testing/dcrdex/README.md

itswisdomagain · 2020-06-10T10:22:27Z

Most of my test attempts ended at trying to pay the fee. over 90%

Could it be related to #392? In any case, a timeout error should show on the test logs, so maybe not. I'll increase the wait period for the fee payment confirmation notice and see if that improves things for you. I guess it may take more than 5 seconds after mining the fee tx for the payment to get confirmed by the client and validated by the server.

Talking about real fee payment errors showing up on the test log, your failure log has an example:
[ERR] CORE: Error getting confirmations for {txid}: -5: no information for transaction.
Looks like the fee waiter fn needs to be improved there, it shouldn't immediately return an error for CoinNotFoundError, should it? On the other hand, since the wallet just broadcasted the tx, why would the wallet be unable to find the tx? Must be that the wallet spent the tx almost immediately, which may be related to the ticketbuyer issue discussed in #392.
UPDATE: The wallets used for trading do not buy tickets, so this probably needs further investigation.

The --race flag seems to give it the time it need to get the fee paid for some reason.

Weird. The success may have nothing to do with using the --race flag though, let's re-check after I increase the fee payment confirm wait period.

itswisdomagain · 2020-06-10T12:08:19Z

there are a lot of races shown.

Resolved in dbdc497

itswisdomagain · 2020-06-10T13:20:10Z

PR #438 is in if you want to update for the refund/find-redeem recovery scenarios.

I wanted to get on the refund scenario test but realized that setting shorter locktime values for test purposes would require more than just changing dex.LockTimeTaker and dex.LockTimeMaker to variables and setting test values from the test code, because the DEX would validate init swaps using the original values not the test values.

The only solution I see here would be changing the values before building dcrdex and running the tests or moving those values to dex cfg variables.

I'll like to get @buck54321's thoughts on this before proceeding.

Related discussion here: #438 (comment).

buck54321 · 2020-06-10T13:59:12Z

I am extremely hesitant to make the locktimes variables. If the purpose is for testing, we would presumably want to allow these to be very low values. But if the operator sets the locktimes too low during normal operation, it could result in a nonsensical scenario where the lock times expire before SwapConf confirmations. Or even worse, the operator might set them backwards and render the atomic swaps unsafe. In theory, this could all be worked out with some sort of validation during start up. We could check locktimes against SwapConf, but that would require asset backends to report some kind of expected block times. We could require LockTimeTaker to be less than LockTimeMaker, but a simple < comparison in insufficient, so we'd need to perform some calculations based on block times and have a formula for minimum time buffer. All of this is within the realm of possibility, but every bit of added complexity adds more potential for catastrophe.

I could maybe get behind this if we only allow them to be variable on simnet.

Something like

core.lockTimeTaker = dex.LockTimeTaker
if cfg.Network == dex.Simnet && cfg.SimLockTimeTaker != 0 {
  core.lockTimeTaker = cfg.SimLockTimeTaker
}
...

chappjc · 2020-06-10T14:11:23Z

But if the operator sets the locktimes too low during normal operation, it could result in a nonsensical scenario where the lock times expire before FundConf confirmations.

Do you mean SwapConf here?

But why not set dex.LockTimeTaker and dex.LockTimeMaker with the build command if it's necessary for tests?

go build -ldflags "-X github.com/decred/dex.LockTimeTaker=something"

They would just need to be vars instead of consts.

buck54321 · 2020-06-10T14:16:35Z

Do you mean SwapConf here?

Yes. Fixed the original now.

buck54321 · 2020-06-10T14:20:04Z

If I'm reading it right, the -X linker option only works for var, and then only for string.

dex/testing/dcr/create-wallet.sh

dex/testing/dcrdex/README.md

dex/testing/dcrdex/harness.sh

chappjc · 2020-06-10T14:34:44Z

dex/testing/dcrdex/harness.sh

+rpclisten=127.0.0.1:17273
+debuglevel=trace
+regfeeconfirms=1
+signingkeypass=keypass


We should add an admin server pass option too. @JoeGruffins would you want to roll up a PR for that? I can grab it too if you have lots of other stuff on your plate.

I can put that up as well if no one is on it yet, when applying the next batch of suggestions on this PR.

If you like, sure. Should be a straightforward dcrdex config change.

Done - #465

About this, the adminsrvpass option isn't really useful without AdminSrvOn and perhaps AdminSrvAddr. Should those be included here as well or leave them all out for the tester to append as args to the harness exec cmd e.g.

dcrdex/harness.sh --adminsrvon --adminsrvpass=pass adminsrvaddr=127.0.0.0:PORT

I meant to respond to this, but yes. Also, we should define and export the dexadm function to work with the harness config. i.e.

dexadm() { curl --cacert somewhere/rpc.cert --basic -u u:adminpass https://127.0.0.1:16542/api/$1 } export -f dexadm

Something like that I think.

run_tests.sh

chappjc · 2020-06-10T14:40:24Z

If I'm reading it right, the -X linker option only works for var, and then only for string.

Right I amended my comment about var vs const, which would be an acceptable change (the op could hack the code just as easily with consts), but I didn't think about the string requirement. Could still be done with a time.Parse, but clearly not as straightforward.

buck54321 · 2020-06-10T14:44:11Z

We could do something similar with build tags, like here, but we'd have to edit code to modify the values, which is not great.

chappjc · 2020-06-10T14:46:02Z

We could do something similar with build tags, like here, but we'd have to edit code to modify the values, which is not great.

I think that's a pretty good idea, although it makes two new files for these two consts.

buck54321 · 2020-06-10T14:48:20Z

It also doesn't allow us to restrict modifications to simnet.

chappjc · 2020-06-10T15:07:19Z

It also doesn't allow us to restrict modifications to simnet.

The restriction is really just to prevent accidentally using the wrong values/build on mainnet or testnet. An op could easily modify a couple lines of code. But we could still restrict modifications to simnet by having the reference mainnet values in two consts that are not changeable by tags or anything short of editing the code, and the configured ones in the tag-settable code, then compare as you suggested.

itswisdomagain · 2020-06-10T16:01:32Z

Combining the recommendations/suggestions above re handling separate simnet test locktime values, here's the path I'm considering:

Keep the current constant values to be used for mainnet.
Add MakerTestLockTime and TakerTestLockTime string variables that may be set at build time with ldflags but only used if running on testnet or simnet.

This way, the same binary can be used for any network and the locktime values can be changed at build time (without editing the code) for testnet or simnet.

Using the additional string values will be if running on testnet or simnet and the values can be parsed into valid time.Duration objects using time.ParseDuration.

chappjc · 2020-06-10T16:04:13Z

Worth hacking it up to see how it looks. The ldflags approach adds more configurability than the build tags, so perhaps the added duration string parsing is worth it.

buck54321 · 2020-06-10T16:08:33Z

Seems legit, @itswisdomagain . Are you going to use some kind of sentinel default for MakerTestLockTime and TakerTestLockTime so that if they aren't set during build they fall back to LockTimeMaker and LockTimeTaker?

itswisdomagain · 2020-06-10T21:21:38Z

Are you going to use some kind of sentinel default for MakerTestLockTime and TakerTestLockTime so that if they aren't set during build they fall back to LockTimeMaker and LockTimeTaker?

Yeah, I'm thinking defaulting both test values to empty strings.

JoeGruffins · 2020-06-11T06:16:08Z

I believe my problems are being caused because the registration fee is paid and then checked in succession in Register, and the wallet is not ready with transaction data when Confirmations is called.
Adding a one second sleep before this line:

dcrdex/client/core/core.go

Line 1095 in ab3dff2

c.verifyRegistrationFee(wallet, dc, coin.ID(), regFeeAssetID)

Solves my testing issue and seems like an ok solution. I am surprised that only I am getting the error though.

chappjc · 2020-06-13T14:17:03Z

No reason not to include them in the harness by default.

itswisdomagain · 2020-06-13T15:23:07Z

dex/asset.go

+	testLockTime struct {
+		taker time.Duration
+		maker time.Duration
+	}


I've made both default and test locktime values unexported, and only exported LockTimeTaker(network)and LockTimeMaker(network) functions to force accessors to provide information about the running network.

One other thought was to export DefaultLockTime{M,T}aker and TestLockTime{M,T}aker and allow accessors perform network checks before accessing either set of variables but that may make it easy for the wrong set of locktime vars to be used. I think it also prevents avoidable repetition of the if net == Mainnet code checks from different usage sites.

This adds a trade_simnet_test that connects to a running dcrdex harness to test different trade sequences. The only trade test implemented in this commit is the test for successful completions of all matches for an order.

This ensures that the trades monitored for each test case executed as expected/desired. In order to ensure balance checks are reliable, non-mining btc and dcr wallets were added to the respective harnesses for use in trading. Mining wallets often get their balances mixed up with mining rewards.

- remove absolute paths computation - dcr-harness: create server_fees account on alpha wallet - dcrdex harness: rebuild dcrdex with test values for maker and taker locktimes - dcrdex harness: drop and re-create the test db - dcrdex harness: change regfeexpub and add shutdown script

- parse test locktime values once, panic on invalid duration values - remove net param from NewSwapper, pass locktimes in swapper cfg

itswisdomagain · 2020-06-16T12:31:55Z

dex/testing/dcrdex/harness.sh

+# DEX admin script
+cat > "${DCRDEX_DATA_DIR}/dexadm" <<EOF
+#!/bin/sh
+curl --cacert ${DCRDEX_DATA_DIR}/rpc.cert --basic -u u:adminpass https://127.0.0.1:16542/api/\$@
+EOF
+chmod +x "${DCRDEX_DATA_DIR}/dexadm"


Initial idea here was to export a function:

dexadm() { curl --cacert somewhere/rpc.cert --basic -u u:adminpass https://127.0.0.1:16542/api/$1 } export -f dexadm

But there are 2 issues with that approach:

function export is a bash-only feature, I remember reading a convo somewhere where bash scripting was discouraged in dcr projects

more importantly though, any exported variable or function only takes effect in the current terminal window which is shortly replaced by the tmux window. When I tested it, any exported variable is only available before attaching the tmux window.

The only other thing I think can be done here is to add a tmux ctrl window where a tester can more easily fiddle with the dexadm script. Ofc, the script can be executed from any other terminal window regardless.

I certainly do not discourage bash scripting. I encourage it. I think there are (t)csh fans abound, but that's their preference. bash is by far the most common shell.

Anyway, putting it into "${DCRDEX_DATA_DIR}/dexadm" is a fine solution.

itswisdomagain force-pushed the trade-tests branch from b966792 to 2a46359 Compare May 31, 2020 22:04

itswisdomagain commented Jun 9, 2020

View reviewed changes

client/core/trade.go Show resolved Hide resolved

dex/testing/btc/harness.sh Show resolved Hide resolved

itswisdomagain force-pushed the trade-tests branch from ea78da8 to 232b487 Compare June 9, 2020 14:17

itswisdomagain mentioned this pull request Jun 9, 2020

core: fix locktime handling #438

Merged

itswisdomagain marked this pull request as ready for review June 9, 2020 14:29

buck54321 mentioned this pull request Jun 9, 2020

testing: need load testing #457

Closed

JoeGruffins reviewed Jun 10, 2020

View reviewed changes

go.mod Outdated Show resolved Hide resolved

dex/testing/dcrdex/harness.sh Outdated Show resolved Hide resolved

dex/testing/dcr/harness.sh Outdated Show resolved Hide resolved

dex/testing/dcrdex/README.md Outdated Show resolved Hide resolved

itswisdomagain mentioned this pull request Jun 10, 2020

core: properly handle client->server request errors during trade #459

Merged

chappjc reviewed Jun 10, 2020

View reviewed changes

itswisdomagain force-pushed the trade-tests branch from dbdc497 to a78aa07 Compare June 10, 2020 23:37

itswisdomagain commented Jun 13, 2020

View reviewed changes

itswisdomagain force-pushed the trade-tests branch from b2337c3 to a91fbd2 Compare June 14, 2020 00:07

itswisdomagain mentioned this pull request Jun 14, 2020

core,dcr: ignoring output from listlockunspent that wasn't found with gettxout #471

Closed

buck54321 approved these changes Jun 15, 2020

View reviewed changes

chappjc approved these changes Jun 15, 2020

View reviewed changes

itswisdomagain added 20 commits June 16, 2020 13:21

dex/testing: add dcrdex harness

244cd85

app: add trade simnet test

6bc7f5c

This adds a trade_simnet_test that connects to a running dcrdex harness to test different trade sequences. The only trade test implemented in this commit is the test for successful completions of all matches for an order.

fix failing tests

e7c60e1

use btc beta wallet instead of alpha wallet

123d963

dcr harness: stop wallets before nodes, dcrdex harness: add readme

7c3741f

add trade failure tests: no maker,taker swap, no maker redeem

f56159f

correct dcrdex readme relative links

3c71d23

use static rpc cert for dcrdex harness, update readme

0849f22

post-rebase corrections

f86b259

fix harness paths inconsistencies, undo mod ver bump

9c74945

increase fee payment wait duration, fix race issues

1dc3745

add support for setting custom locktimes on simnet,testnet

f92d584

update tests to check successful execution of auto-refunds

23d8178

refactor test code

1a9e075

improve swap locktimes handling

d8f9a1a

- parse test locktime values once, panic on invalid duration values - remove net param from NewSwapper, pass locktimes in swapper cfg

add adminsrv options to dcrdex harness cfg

69f01fb

re-register DEX after client inaction

d90dbf7

add dexadm script

27bdd94

itswisdomagain force-pushed the trade-tests branch from 7ff999e to 27bdd94 Compare June 16, 2020 12:24

itswisdomagain commented Jun 16, 2020

View reviewed changes

chappjc merged commit 1e9144d into decred:master Jun 16, 2020

itswisdomagain deleted the trade-tests branch June 16, 2020 16:58

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add simnet trading tests #432

Add simnet trading tests #432

itswisdomagain commented May 31, 2020 •

edited

Loading

itswisdomagain commented May 31, 2020 •

edited

Loading

itswisdomagain commented Jun 9, 2020

chappjc commented Jun 9, 2020

JoeGruffins left a comment

itswisdomagain commented Jun 10, 2020 •

edited

Loading

itswisdomagain commented Jun 10, 2020

itswisdomagain commented Jun 10, 2020 •

edited

Loading

buck54321 commented Jun 10, 2020 •

edited

Loading

chappjc commented Jun 10, 2020 •

edited

Loading

buck54321 commented Jun 10, 2020

buck54321 commented Jun 10, 2020

chappjc Jun 10, 2020 •

edited

Loading

itswisdomagain Jun 10, 2020

chappjc Jun 10, 2020

itswisdomagain Jun 11, 2020

itswisdomagain Jun 13, 2020

chappjc Jun 15, 2020 •

edited

Loading

chappjc commented Jun 10, 2020

buck54321 commented Jun 10, 2020

chappjc commented Jun 10, 2020

buck54321 commented Jun 10, 2020

chappjc commented Jun 10, 2020

itswisdomagain commented Jun 10, 2020

chappjc commented Jun 10, 2020

buck54321 commented Jun 10, 2020

itswisdomagain commented Jun 10, 2020

JoeGruffins commented Jun 11, 2020

chappjc commented Jun 13, 2020

itswisdomagain Jun 13, 2020

itswisdomagain Jun 16, 2020

chappjc Jun 16, 2020

Add simnet trading tests #432

Add simnet trading tests #432

Conversation

itswisdomagain commented May 31, 2020 • edited Loading

itswisdomagain commented May 31, 2020 • edited Loading

itswisdomagain commented Jun 9, 2020

chappjc commented Jun 9, 2020

JoeGruffins left a comment

Choose a reason for hiding this comment

itswisdomagain commented Jun 10, 2020 • edited Loading

itswisdomagain commented Jun 10, 2020

itswisdomagain commented Jun 10, 2020 • edited Loading

buck54321 commented Jun 10, 2020 • edited Loading

chappjc commented Jun 10, 2020 • edited Loading

buck54321 commented Jun 10, 2020

buck54321 commented Jun 10, 2020

chappjc Jun 10, 2020 • edited Loading

Choose a reason for hiding this comment

itswisdomagain Jun 10, 2020

Choose a reason for hiding this comment

chappjc Jun 10, 2020

Choose a reason for hiding this comment

itswisdomagain Jun 11, 2020

Choose a reason for hiding this comment

itswisdomagain Jun 13, 2020

Choose a reason for hiding this comment

chappjc Jun 15, 2020 • edited Loading

Choose a reason for hiding this comment

chappjc commented Jun 10, 2020

buck54321 commented Jun 10, 2020

chappjc commented Jun 10, 2020

buck54321 commented Jun 10, 2020

chappjc commented Jun 10, 2020

itswisdomagain commented Jun 10, 2020

chappjc commented Jun 10, 2020

buck54321 commented Jun 10, 2020

itswisdomagain commented Jun 10, 2020

JoeGruffins commented Jun 11, 2020

chappjc commented Jun 13, 2020

itswisdomagain Jun 13, 2020

Choose a reason for hiding this comment

itswisdomagain Jun 16, 2020

Choose a reason for hiding this comment

chappjc Jun 16, 2020

Choose a reason for hiding this comment

itswisdomagain commented May 31, 2020 •

edited

Loading

itswisdomagain commented May 31, 2020 •

edited

Loading

itswisdomagain commented Jun 10, 2020 •

edited

Loading

itswisdomagain commented Jun 10, 2020 •

edited

Loading

buck54321 commented Jun 10, 2020 •

edited

Loading

chappjc commented Jun 10, 2020 •

edited

Loading

chappjc Jun 10, 2020 •

edited

Loading

chappjc Jun 15, 2020 •

edited

Loading