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.

Sign up for GitHub

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

Jump to bottom

MARKETTEST: Go CI test time out. #286

Closed
JoeGruffins opened this issue Apr 23, 2020 · 2 comments
Closed

MARKETTEST: Go CI test time out. #286

JoeGruffins opened this issue Apr 23, 2020 · 2 comments
Assignees
@chappjc

Comments

@JoeGruffins
Copy link
Member

JoeGruffins commented Apr 23, 2020 •
edited by chappjc
Loading

Full log:

log 
2020-04-23T01:30:46.5829982Z HEAD is now at 3f7dffb Merge 124c0e04554992db2cbdba8ec20eac110658cc4a into 605ccfaed4a544b11f219eed917bf34e09e94330
2020-04-23T01:30:46.5879062Z ##[group]Run curl -sfL https://install.goreleaser.com/github.com/golangci/golangci-lint.sh | sh -s -- -b $(go env GOPATH)/bin v1.24.0
2020-04-23T01:30:46.5879383Z �[36;1mcurl -sfL https://install.goreleaser.com/github.com/golangci/golangci-lint.sh | sh -s -- -b $(go env GOPATH)/bin v1.24.0�[0m
2020-04-23T01:30:46.5918890Z shell: /bin/bash -e {0}
2020-04-23T01:30:46.5919014Z env:
2020-04-23T01:30:46.5919121Z   GOROOT: /opt/hostedtoolcache/go/1.14.2/x64
2020-04-23T01:30:46.5919228Z ##[endgroup]
2020-04-23T01:30:46.7923512Z golangci/golangci-lint info checking GitHub for tag 'v1.24.0'
2020-04-23T01:30:46.8504732Z golangci/golangci-lint info found version: 1.24.0 for v1.24.0/linux/amd64
2020-04-23T01:30:47.4717189Z golangci/golangci-lint info installed /home/runner/go/bin/golangci-lint
2020-04-23T01:30:47.4836545Z ##[group]Run go build -race ./...
2020-04-23T01:30:47.4836743Z �[36;1mgo build -race ./...�[0m
2020-04-23T01:30:47.4880054Z shell: /bin/bash -e {0}
2020-04-23T01:30:47.4880169Z env:
2020-04-23T01:30:47.4880289Z   GOROOT: /opt/hostedtoolcache/go/1.14.2/x64
2020-04-23T01:30:47.4880397Z   GO111MODULE: on
2020-04-23T01:30:47.4880499Z ##[endgroup]
2020-04-23T01:30:52.1281392Z go: downloading github.com/decred/dcrd/rpcclient/v5 v5.0.0
2020-04-23T01:30:52.1324719Z go: downloading github.com/decred/dcrd/wire v1.3.0
2020-04-23T01:30:52.1328830Z go: downloading github.com/decred/dcrd/chaincfg/v2 v2.3.0
2020-04-23T01:30:52.1332551Z go: downloading github.com/decred/dcrd/dcrec v1.0.0
2020-04-23T01:30:52.1350439Z go: downloading github.com/btcsuite/btcd v0.20.1-beta
2020-04-23T01:30:52.1380043Z go: downloading github.com/decred/dcrwallet/rpc/jsonrpc/types v1.4.0
2020-04-23T01:30:52.1390365Z go: downloading github.com/decred/dcrd/txscript/v2 v2.1.0
2020-04-23T01:30:52.1422594Z go: downloading github.com/decred/dcrd/dcrutil/v2 v2.0.1
2020-04-23T01:30:52.1459300Z go: downloading github.com/decred/dcrd/dcrec/secp256k1 v1.0.2
2020-04-23T01:30:52.1571920Z go: downloading github.com/decred/dcrd/rpc/jsonrpc/types v1.0.1
2020-04-23T01:30:52.1635056Z go: downloading github.com/decred/dcrd/certgen v1.1.0
2020-04-23T01:30:52.1673027Z go: downloading github.com/decred/base58 v1.0.1
2020-04-23T01:30:52.2036404Z go: downloading github.com/decred/dcrd/gcs v1.1.0
2020-04-23T01:30:52.2298770Z go: downloading golang.org/x/crypto v0.0.0-20191122220453-ac88ee75c92c
2020-04-23T01:30:52.2310942Z go: downloading github.com/decred/dcrd/rpc/jsonrpc/types/v2 v2.0.0
2020-04-23T01:30:52.2343473Z go: downloading github.com/decred/dcrd/crypto/ripemd160 v1.0.0
2020-04-23T01:30:52.2386581Z go: downloading github.com/decred/dcrd/gcs/v2 v2.0.0
2020-04-23T01:30:52.2397799Z go: downloading github.com/go-chi/chi v4.0.2+incompatible
2020-04-23T01:30:52.3046574Z go: downloading github.com/decred/dcrd/dcrec/secp256k1/v2 v2.0.0
2020-04-23T01:30:52.3208622Z go: downloading github.com/btcsuite/btcutil v0.0.0-20190425235716-9e5f4b9a998d
2020-04-23T01:30:52.4119436Z go: downloading github.com/decred/dcrd/chaincfg/chainhash v1.0.2
2020-04-23T01:30:52.4440232Z go: downloading github.com/decred/dcrd/crypto/blake256 v1.0.0
2020-04-23T01:30:52.4621473Z go: downloading github.com/decred/dcrd/blockchain/stake/v2 v2.0.2
2020-04-23T01:30:52.5662898Z go: downloading github.com/ltcsuite/ltcd v0.0.0-20190519120615-e27ee083f08f
2020-04-23T01:30:52.5702102Z go: downloading github.com/decred/dcrd/database/v2 v2.0.1
2020-04-23T01:30:52.5726574Z go: downloading github.com/jessevdk/go-flags v1.4.0
2020-04-23T01:30:52.6134996Z go: downloading github.com/decred/go-socks v1.1.0
2020-04-23T01:30:52.6382442Z go: downloading github.com/gorilla/websocket v1.4.1
2020-04-23T01:30:52.6394427Z go: downloading github.com/decred/dcrd/hdkeychain/v2 v2.1.0
2020-04-23T01:30:52.6414805Z go: downloading golang.org/x/sys v0.0.0-20200202164722-d101bd2416d5
2020-04-23T01:30:52.6456287Z go: downloading github.com/lib/pq v1.2.0
2020-04-23T01:30:52.6462042Z go: downloading go.etcd.io/bbolt v1.3.4
2020-04-23T01:30:52.6475647Z go: downloading github.com/decred/dcrd/dcrec/edwards v1.0.0
2020-04-23T01:30:52.6483140Z go: downloading github.com/decred/dcrd/dcrjson/v3 v3.0.1
2020-04-23T01:30:52.6568252Z go: downloading github.com/btcsuite/websocket v0.0.0-20150119174127-31079b680792
2020-04-23T01:30:52.7008791Z go: downloading github.com/dchest/siphash v1.2.1
2020-04-23T01:30:52.7103560Z go: downloading github.com/btcsuite/go-socks v0.0.0-20170105172521-4720035b7bfd
2020-04-23T01:30:52.7104129Z go: downloading github.com/decred/dcrwallet/wallet/v3 v3.1.1-0.20191230143837-6a86dc4676f0
2020-04-23T01:30:52.7175463Z go: downloading github.com/decred/slog v1.0.0
2020-04-23T01:30:52.7215129Z go: downloading github.com/btcsuite/btclog v0.0.0-20170628155309-84c8d2346e9f
2020-04-23T01:30:52.7666158Z go: downloading github.com/decred/dcrd/dcrec/edwards/v2 v2.0.0
2020-04-23T01:30:52.8193372Z go: downloading github.com/agl/ed25519 v0.0.0-20170116200512-5312a6153412
2020-04-23T01:31:04.5826960Z ##[group]Run export PATH=${PATH}:$(go env GOPATH)/bin
2020-04-23T01:31:04.5827141Z �[36;1mexport PATH=${PATH}:$(go env GOPATH)/bin�[0m
2020-04-23T01:31:04.5827238Z �[36;1m./run_tests.sh�[0m
2020-04-23T01:31:04.5860171Z shell: /bin/bash -e {0}
2020-04-23T01:31:04.5860272Z env:
2020-04-23T01:31:04.5860364Z   GOROOT: /opt/hostedtoolcache/go/1.14.2/x64
2020-04-23T01:31:04.5860454Z   GO111MODULE: on
2020-04-23T01:31:04.5860520Z ##[endgroup]
2020-04-23T01:31:04.5983373Z ++ pwd
2020-04-23T01:31:04.5985562Z + dir=/home/runner/work/dcrdex/dcrdex
2020-04-23T01:31:04.5986641Z + modules='. client/cmd/dexcctl'
2020-04-23T01:31:04.5987058Z + for m in $modules
2020-04-23T01:31:04.5987688Z + cd /home/runner/work/dcrdex/dcrdex/.
2020-04-23T01:31:04.5988488Z + env GORACE=halt_on_error=1 go test -race -short ./...
2020-04-23T01:31:06.3692551Z ?   	decred.org/dcrdex/client/asset	[no test files]
2020-04-23T01:31:11.6959061Z ok  	decred.org/dcrdex/client/asset/btc	0.780s
2020-04-23T01:31:13.3657851Z ok  	decred.org/dcrdex/client/asset/dcr	0.758s
2020-04-23T01:31:16.6894785Z ok  	decred.org/dcrdex/client/comms	1.073s
2020-04-23T01:31:18.4278433Z ok  	decred.org/dcrdex/client/core	1.934s
2020-04-23T01:31:18.4279620Z ?   	decred.org/dcrdex/client/db	[no test files]
2020-04-23T01:31:18.8462995Z ok  	decred.org/dcrdex/client/db/bolt	1.252s
2020-04-23T01:32:06.7043408Z ok  	decred.org/dcrdex/client/db/test	47.759s
2020-04-23T01:32:06.7044471Z ok  	decred.org/dcrdex/client/order	0.662s
2020-04-23T01:32:06.7045037Z ok  	decred.org/dcrdex/client/rpcserver	1.848s
2020-04-23T01:32:06.7045584Z ok  	decred.org/dcrdex/client/webserver	0.807s
2020-04-23T01:32:06.7046035Z ok  	decred.org/dcrdex/dex	0.024s
2020-04-23T01:32:06.7046574Z ok  	decred.org/dcrdex/dex/btc	0.695s
2020-04-23T01:32:06.7047064Z ?   	decred.org/dcrdex/dex/calc	[no test files]
2020-04-23T01:32:06.7047584Z ok  	decred.org/dcrdex/dex/dcr	0.732s
2020-04-23T01:32:06.7048048Z ok  	decred.org/dcrdex/dex/encode	0.026s
2020-04-23T01:32:06.7048549Z ok  	decred.org/dcrdex/dex/encrypt	1.380s
2020-04-23T01:32:06.7049023Z ok  	decred.org/dcrdex/dex/msgjson	0.034s
2020-04-23T01:32:06.7049523Z ok  	decred.org/dcrdex/dex/order	0.673s
2020-04-23T01:32:06.7049995Z ok  	decred.org/dcrdex/dex/order/test	4.589s
2020-04-23T01:32:06.7050505Z ?   	decred.org/dcrdex/dex/wait	[no test files]
2020-04-23T01:32:06.7050956Z ?   	decred.org/dcrdex/dex/ws	[no test files]
2020-04-23T01:32:06.7051459Z ok  	decred.org/dcrdex/server/account	0.667s
2020-04-23T01:32:06.7051956Z ?   	decred.org/dcrdex/server/account/pki	[no test files]
2020-04-23T01:32:06.7052472Z ok  	decred.org/dcrdex/server/admin	0.861s
2020-04-23T01:32:06.7052962Z ?   	decred.org/dcrdex/server/asset	[no test files]
2020-04-23T01:32:06.7053486Z ok  	decred.org/dcrdex/server/asset/btc	1.985s
2020-04-23T01:32:06.7053942Z ok  	decred.org/dcrdex/server/asset/dcr	1.111s
2020-04-23T01:32:06.7054455Z ok  	decred.org/dcrdex/server/asset/ltc	0.692s
2020-04-23T01:32:06.7054919Z ok  	decred.org/dcrdex/server/auth	1.974s
2020-04-23T01:32:06.7055424Z ok  	decred.org/dcrdex/server/book	2.469s
2020-04-23T01:32:06.7055904Z ok  	decred.org/dcrdex/server/coinlock	0.688s
2020-04-23T01:32:06.7056386Z ok  	decred.org/dcrdex/server/comms	1.659s
2020-04-23T01:32:06.7056845Z ok  	decred.org/dcrdex/server/db	0.658s
2020-04-23T01:32:07.1754524Z ok  	decred.org/dcrdex/server/db/driver/pg	0.689s
2020-04-23T01:32:07.1754899Z ?   	decred.org/dcrdex/server/db/driver/pg/internal	[no test files]
2020-04-23T01:32:07.1755115Z ?   	decred.org/dcrdex/server/dex	[no test files]
2020-04-23T01:42:09.4496132Z 2020-04-23 01:32:09.337 [INF] MARKETTEST: Route for limit
2020-04-23T01:42:09.4497253Z 2020-04-23 01:32:09.337 [INF] MARKETTEST: Route for market
2020-04-23T01:42:09.4498573Z 2020-04-23 01:32:09.337 [INF] MARKETTEST: Route for cancel
2020-04-23T01:42:09.4499292Z 2020-04-23 01:32:09.439 [INF] MARKETTEST: Route for init
2020-04-23T01:42:09.4500096Z 2020-04-23 01:32:09.439 [INF] MARKETTEST: Route for redeem
2020-04-23T01:42:09.4504826Z 2020-04-23 01:32:09.439 [DBG] MARKETTEST: Locking 0 base asset coins.
2020-04-23T01:42:09.4505377Z 2020-04-23 01:32:09.439 [DBG] MARKETTEST: Locking 0 quote asset coins.
2020-04-23T01:42:09.4505717Z 2020-04-23 01:32:09.608 [INF] MARKETTEST: Route for init
2020-04-23T01:42:09.4506044Z 2020-04-23 01:32:09.608 [INF] MARKETTEST: Route for redeem
2020-04-23T01:42:09.4506364Z 2020-04-23 01:32:09.608 [DBG] MARKETTEST: Locking 0 base asset coins.
2020-04-23T01:42:09.4506709Z 2020-04-23 01:32:09.608 [DBG] MARKETTEST: Locking 0 quote asset coins.
2020-04-23T01:42:09.4507079Z 2020-04-23 01:32:09.733 [DBG] MARKETTEST: Order type limit received prior to market start.
2020-04-23T01:42:09.4507410Z 2020-04-23 01:32:10.000 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4508229Z 2020-04-23 01:32:10.001 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008. Message: {"type":2,"id":2,"payload":{"result":{"sig":"","orderid":"b3edfe2835e051e11c63ba14eea9629ace76bf152ef515b6fe00ff0d19dcfa0a","tserver":1587605530000}}}
2020-04-23T01:42:09.4508717Z 2020-04-23 01:32:10.001 [INF] MARKETTEST: preimage found for msg id 2: 4e05b377241e73a883dd77aff0302c6da8665c42341dda4adaea595ab1895f96
2020-04-23T01:42:09.4509148Z 2020-04-23 01:32:10.001 [DBG] MARKETTEST: setting preimage for order b3edfe2835e051e11c63ba14eea9629ace76bf152ef515b6fe00ff0d19dcfa0a
2020-04-23T01:42:09.4509576Z 2020-04-23 01:32:10.500 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008
2020-04-23T01:42:09.4509999Z 2020-04-23 01:32:10.500 [INF] MARKETTEST: order id: b3edfe2835e051e11c63ba14eea9629ace76bf152ef515b6fe00ff0d19dcfa0a
2020-04-23T01:42:09.4510429Z 2020-04-23 01:32:10.500 [INF] MARKETTEST: found preimage: 4e05b377241e73a883dd77aff0302c6da8665c42341dda4adaea595ab1895f96
2020-04-23T01:42:09.4510914Z 2020-04-23 01:32:10.626 [INF] MARKETTEST: Collected 1 valid order preimages, missed 0. Commit checksum: 5b1f10ccc47ad7f656929c80ae86a73ac7aead686277fb9e744e430aaca84c3e
2020-04-23T01:42:09.4511465Z 2020-04-23 01:32:10.628 [INF] MARKETTEST: Matching complete for market dcr_btc epoch 3175211060: 0 matches (0 partial fills), 0 completed OK (not booked), 1 booked, 0 unbooked, 0 failed
2020-04-23T01:42:09.4512120Z 2020-04-23 01:32:10.646 [DBG] MARKETTEST: Cancel order 888ba970e5d9ab49a918127291ea365c98f07adfd40a4a00afa6bbaa666330c9 (account=224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000009) does not own target order b3edfe2835e051e11c63ba14eea9629ace76bf152ef515b6fe00ff0d19dcfa0a.
2020-04-23T01:42:09.4512467Z 2020-04-23 01:32:10.647 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4513060Z 2020-04-23 01:32:10.647 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008. Message: {"type":2,"id":3,"payload":{"result":{"sig":"","orderid":"66551e2e60b48a37d9cd339969bf293eac8d1b31ab2f519fd38b04db10234cb0","tserver":1587605530647}}}
2020-04-23T01:42:09.4513545Z 2020-04-23 01:32:10.647 [INF] MARKETTEST: preimage found for msg id 3: 52489dd2ceb49c2474303cbb44c2b94303db662c9c66b8782905190f1e1635b6
2020-04-23T01:42:09.4513990Z 2020-04-23 01:32:10.647 [DBG] MARKETTEST: setting preimage for order 66551e2e60b48a37d9cd339969bf293eac8d1b31ab2f519fd38b04db10234cb0
2020-04-23T01:42:09.4514639Z 2020-04-23 01:32:10.647 [DBG] MARKETTEST: Received cancel order 80734f178fb69b49b3ad8d57649abbdb6a9617a0d00c8b1c8965e304fdb4a2c2 targeting b3edfe2835e051e11c63ba14eea9629ace76bf152ef515b6fe00ff0d19dcfa0a, but already have 66551e2e60b48a37d9cd339969bf293eac8d1b31ab2f519fd38b04db10234cb0.
2020-04-23T01:42:09.4515215Z 2020-04-23 01:32:11.000 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008
2020-04-23T01:42:09.4515638Z 2020-04-23 01:32:11.000 [INF] MARKETTEST: order id: 66551e2e60b48a37d9cd339969bf293eac8d1b31ab2f519fd38b04db10234cb0
2020-04-23T01:42:09.4516070Z 2020-04-23 01:32:11.000 [INF] MARKETTEST: found preimage: 52489dd2ceb49c2474303cbb44c2b94303db662c9c66b8782905190f1e1635b6
2020-04-23T01:42:09.4516726Z 2020-04-23 01:32:11.126 [INF] MARKETTEST: Collected 1 valid order preimages, missed 0. Commit checksum: ae34a2251d28cfd69e1d71ee37a6632cfd73b291b4977549196f998d6ec076e5
2020-04-23T01:42:09.4517270Z 2020-04-23 01:32:11.126 [INF] MARKETTEST: Matching complete for market dcr_btc epoch 3175211061: 1 matches (0 partial fills), 1 completed OK (not booked), 0 booked, 1 unbooked, 0 failed
2020-04-23T01:42:09.4517661Z 2020-04-23 01:32:11.126 [DBG] MARKETTEST: Negotiating 1 matches for epoch 3175211061:500
2020-04-23T01:42:09.4517962Z 2020-04-23 01:32:11.126 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4518347Z 2020-04-23 01:32:11.126 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4518774Z 2020-04-23 01:32:11.126 [DBG] MARKETTEST: orderOffBook: untracked order b3edfe2835e051e11c63ba14eea9629ace76bf152ef515b6fe00ff0d19dcfa0a
2020-04-23T01:42:09.4519375Z 2020-04-23 01:32:11.127 [DBG] MARKETTEST: Negotiate: sending 'match' ack request to user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008 for 2 matches
2020-04-23T01:42:09.4519816Z 2020-04-23 01:32:11.127 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008
2020-04-23T01:42:09.4520152Z 2020-04-23 01:32:11.293 [DBG] MARKETTEST: Market "dcr_btc" stopped.
2020-04-23T01:42:09.4520485Z 2020-04-23 01:32:11.293 [INF] MARKETTEST: Route for init
2020-04-23T01:42:09.4520813Z 2020-04-23 01:32:11.293 [INF] MARKETTEST: Route for redeem
2020-04-23T01:42:09.4521155Z 2020-04-23 01:32:11.293 [DBG] MARKETTEST: Locking 0 base asset coins.
2020-04-23T01:42:09.4521482Z 2020-04-23 01:32:11.293 [DBG] MARKETTEST: Locking 0 quote asset coins.
2020-04-23T01:42:09.4521858Z 2020-04-23 01:32:11.613 [WRN] MARKETTEST: Run: startEpochIdx not set. Starting at the next epoch.
2020-04-23T01:42:09.4522190Z 2020-04-23 01:32:12.000 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4522807Z 2020-04-23 01:32:12.000 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008. Message: {"type":2,"id":6,"payload":{"result":{"sig":"","orderid":"7e5f1dcd37fb3fc53082a87a4c5cbc78c18b425d917ff35d8077b4b49ba0d997","tserver":1587605532000}}}
2020-04-23T01:42:09.4523278Z 2020-04-23 01:32:12.000 [INF] MARKETTEST: preimage found for msg id 6: 4e05b377241e73a883dd77aff0302c6da8665c42341dda4adaea595ab1895f96
2020-04-23T01:42:09.4523721Z 2020-04-23 01:32:12.000 [DBG] MARKETTEST: setting preimage for order 7e5f1dcd37fb3fc53082a87a4c5cbc78c18b425d917ff35d8077b4b49ba0d997
2020-04-23T01:42:09.4524435Z 2020-04-23 01:32:12.001 [DBG] MARKETTEST: Received order 90736c28e875eabbf18b00162de80ce7060428551fe0df7e62cd9be40d3ba93e with commitment 61626137353134306231663665646632363935356139376531623039643762313761626463396330623039396663373364393732393530313635326662663636 also used in previous order 7e5f1dcd37fb3fc53082a87a4c5cbc78c18b425d917ff35d8077b4b49ba0d997!
2020-04-23T01:42:09.4525232Z 2020-04-23 01:32:12.001 [DBG] MARKETTEST: SubmitOrderAsync: Invalid order received: 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c000000080000002a000000000100000171a4a9e59affffc77cedd32800aba75140b1f6edf26955a97e1b09d7b17abdc9c0b099fc73d9729501652fbf6600010000000006422c4031385a7066743833656f76353669455357755070563858464c4a316238674d5a79370000000005f5e10001: order failed validation
2020-04-23T01:42:09.4525601Z 2020-04-23 01:32:12.001 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4526206Z 2020-04-23 01:32:12.001 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008. Message: {"type":2,"id":7,"payload":{"result":{"sig":"","orderid":"90736c28e875eabbf18b00162de80ce7060428551fe0df7e62cd9be40d3ba93e","tserver":1587605532001}}}
2020-04-23T01:42:09.4526673Z 2020-04-23 01:32:12.001 [INF] MARKETTEST: preimage found for msg id 7: 4e05b377241e73a883dd77aff0302c6da8665c42341dda4adaea595ab1895f96
2020-04-23T01:42:09.4527119Z 2020-04-23 01:32:12.001 [DBG] MARKETTEST: setting preimage for order 90736c28e875eabbf18b00162de80ce7060428551fe0df7e62cd9be40d3ba93e
2020-04-23T01:42:09.4527607Z 2020-04-23 01:32:12.500 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008
2020-04-23T01:42:09.4528074Z 2020-04-23 01:32:12.500 [INF] MARKETTEST: order id: 7e5f1dcd37fb3fc53082a87a4c5cbc78c18b425d917ff35d8077b4b49ba0d997
2020-04-23T01:42:09.4528507Z 2020-04-23 01:32:12.500 [INF] MARKETTEST: found preimage: 4e05b377241e73a883dd77aff0302c6da8665c42341dda4adaea595ab1895f96
2020-04-23T01:42:09.4528927Z 2020-04-23 01:32:12.501 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008
2020-04-23T01:42:09.4529346Z 2020-04-23 01:32:12.501 [INF] MARKETTEST: order id: 90736c28e875eabbf18b00162de80ce7060428551fe0df7e62cd9be40d3ba93e
2020-04-23T01:42:09.4529750Z 2020-04-23 01:32:12.501 [INF] MARKETTEST: found preimage: 4e05b377241e73a883dd77aff0302c6da8665c42341dda4adaea595ab1895f96
2020-04-23T01:42:09.4530716Z 2020-04-23 01:32:12.626 [DBG] MARKETTEST: error going to user 32323463626161616661383062663362643166663733313539306263626464613561373666393165363061313536393934363334653931633030303030303038, code: 31, msg: preimage hash 62313639333036393066626131653836663333353562656566383534333065313535363132643335333330316464623438346131666238626534303163313161 does not match order commitment 61626137353134306231663665646632363935356139376531623039643762313761626463396330623039396663373364393732393530313635326662663636
2020-04-23T01:42:09.4531643Z 2020-04-23 01:32:12.626 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008. Message: {"type":2,"id":5,"payload":{"result":null,"error":{"code":31,"message":"preimage hash 62313639333036393066626131653836663333353562656566383534333065313535363132643335333330316464623438346131666238626534303163313161 does not match order commitment 61626137353134306231663665646632363935356139376531623039643762313761626463396330623039396663373364393732393530313635326662663636"}}}
2020-04-23T01:42:09.4532182Z 2020-04-23 01:32:12.627 [INF] MARKETTEST: Collected 0 valid order preimages, missed 2. Commit checksum: 0c03b6b38e3aa05c61284ac498ea15f1ceaf1700f78d5fd2007e479942eb3bf2
2020-04-23T01:42:09.4532625Z 2020-04-23 01:32:12.627 [INF] MARKETTEST: Penalize for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008
2020-04-23T01:42:09.4533058Z 2020-04-23 01:32:12.627 [INF] MARKETTEST: Penalize for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008
2020-04-23T01:42:09.4533881Z 2020-04-23 01:32:12.627 [DBG] MARKETTEST: error going to user 32323463626161616661383062663362643166663733313539306263626464613561373666393165363061313536393934363334653931633030303030303038, code: 31, msg: preimage hash 62313639333036393066626131653836663333353562656566383534333065313535363132643335333330316464623438346131666238626534303163313161 does not match order commitment 61626137353134306231663665646632363935356139376531623039643762313761626463396330623039396663373364393732393530313635326662663636
2020-04-23T01:42:09.4610075Z 2020-04-23 01:32:12.627 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000008. Message: {"type":2,"id":5,"payload":{"result":null,"error":{"code":31,"message":"preimage hash 62313639333036393066626131653836663333353562656566383534333065313535363132643335333330316464623438346131666238626534303163313161 does not match order commitment 61626137353134306231663665646632363935356139376531623039643762313761626463396330623039396663373364393732393530313635326662663636"}}}
2020-04-23T01:42:09.4610663Z 2020-04-23 01:32:12.646 [DBG] MARKETTEST: Received order %!v(PANIC=String method: Order's ServerTime is unset) with zero-value Commitment. Rejecting.
2020-04-23T01:42:09.4611428Z 2020-04-23 01:32:12.646 [DBG] MARKETTEST: SubmitOrderAsync: Invalid order received: 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c000000080000002a000000000100000171a4a9e59affffc77cedd32800000000000000000000000000000000000000000000000000000000000000000000010000000005f5e10031385a7066743833656f76353669455357755070563858464c4a316238674d5a79370000000005f5e10001: order commitment invalid
2020-04-23T01:42:09.4612054Z 2020-04-23 01:32:12.646 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4612705Z 2020-04-23 01:32:12.647 [ERR] MARKETTEST: Failed to process order 9692e11c746aff664e450af18ded9bdae2795c2562692591d8bdf78a806a0c79: processOrder: Failed to store new epoch order 9692e11c746aff664e450af18ded9bdae2795c2562692591d8bdf78a806a0c79: barf
2020-04-23T01:42:09.4613092Z 2020-04-23 01:32:12.647 [DBG] MARKETTEST: Market "dcr_btc" stopped.
2020-04-23T01:42:09.4613407Z 2020-04-23 01:32:12.647 [INF] MARKETTEST: Route for init
2020-04-23T01:42:09.4613737Z 2020-04-23 01:32:12.647 [INF] MARKETTEST: Route for redeem
2020-04-23T01:42:09.4614079Z 2020-04-23 01:32:12.647 [DBG] MARKETTEST: Locking 0 base asset coins.
2020-04-23T01:42:09.4614422Z 2020-04-23 01:32:12.647 [DBG] MARKETTEST: Locking 0 quote asset coins.
2020-04-23T01:42:09.4614998Z 2020-04-23 01:32:12.791 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006
2020-04-23T01:42:09.4615413Z 2020-04-23 01:32:12.792 [INF] MARKETTEST: order id: d9cb2e2ed0616a901762f7e308debd20a702d7e6741687a4faaadaa7e7655c0e
2020-04-23T01:42:09.4615845Z 2020-04-23 01:32:12.792 [INF] MARKETTEST: found preimage: 4e05b377241e73a883dd77aff0302c6da8665c42341dda4adaea595ab1895f96
2020-04-23T01:42:09.4616274Z 2020-04-23 01:32:12.792 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000005
2020-04-23T01:42:09.4616696Z 2020-04-23 01:32:12.792 [INF] MARKETTEST: order id: a161e9fecc0a49e60de72d2ed8d93ff43335b06d4e9ef004deb1b3748ac20875
2020-04-23T01:42:09.4617117Z 2020-04-23 01:32:12.792 [INF] MARKETTEST: found preimage: 52489dd2ceb49c2474303cbb44c2b94303db662c9c66b8782905190f1e1635b6
2020-04-23T01:42:09.4617604Z 2020-04-23 01:32:12.918 [INF] MARKETTEST: Collected 2 valid order preimages, missed 0. Commit checksum: 4859aa186630c2b135074037a8db42f240bbbe81c1361d8783aa605ed3f0cf90
2020-04-23T01:42:09.4618093Z 2020-04-23 01:32:12.919 [INF] MARKETTEST: Matching complete for market dcr_btc epoch 123413513: 2 matches (1 partial fills), 1 completed OK (not booked), 1 booked, 2 unbooked, 0 failed
2020-04-23T01:42:09.4618484Z 2020-04-23 01:32:12.919 [DBG] MARKETTEST: Negotiating 2 matches for epoch 123413513:500
2020-04-23T01:42:09.4618807Z 2020-04-23 01:32:12.919 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4619114Z 2020-04-23 01:32:12.919 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4619425Z 2020-04-23 01:32:12.919 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4619717Z 2020-04-23 01:32:12.919 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4620155Z 2020-04-23 01:32:12.919 [DBG] MARKETTEST: orderOffBook: untracked order 7ad0101ab795d595091fbc084aebb4ac5fe2bc78cffa5b5e6d2392a65c197427
2020-04-23T01:42:09.4620633Z 2020-04-23 01:32:12.919 [DBG] MARKETTEST: Negotiate: sending 'match' ack request to user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000005 for 2 matches
2020-04-23T01:42:09.4621071Z 2020-04-23 01:32:12.919 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000005
2020-04-23T01:42:09.4621550Z 2020-04-23 01:32:12.919 [DBG] MARKETTEST: Negotiate: sending 'match' ack request to user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006 for 2 matches
2020-04-23T01:42:09.4622483Z 2020-04-23 01:32:12.920 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006
2020-04-23T01:42:09.4622921Z 2020-04-23 01:32:12.970 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000005
2020-04-23T01:42:09.4623343Z 2020-04-23 01:32:12.970 [INF] MARKETTEST: order id: 3b045eaf5b57a45b1bd46f3a354c0592e650f2e89cbccc7af7ce45f7a5c4f627
2020-04-23T01:42:09.4623765Z 2020-04-23 01:32:12.970 [INF] MARKETTEST: found preimage: e1f796fa0fc16ba7bb90be2a33e87c3d60ab628471a420834383661801bb0bfd
2020-04-23T01:42:09.4624251Z 2020-04-23 01:32:13.096 [INF] MARKETTEST: Collected 1 valid order preimages, missed 0. Commit checksum: a958ef5d180cb9dabf4d6aa120489955e6ad04bcba3414d1f4cf1725ed7e0634
2020-04-23T01:42:09.4624938Z 2020-04-23 01:32:13.096 [DBG] MARKETTEST: Failed to remove order 3b045eaf5b57a45b1bd46f3a354c0592e650f2e89cbccc7af7ce45f7a5c4f627 set by a cancel order 3e34878d3f246fadfce344e74ef813090f8030bcd525ac10653ff182e00120f7
2020-04-23T01:42:09.4625488Z 2020-04-23 01:32:13.096 [INF] MARKETTEST: Matching complete for market dcr_btc epoch 123413513: 0 matches (0 partial fills), 0 completed OK (not booked), 0 booked, 0 unbooked, 1 failed
2020-04-23T01:42:09.4625818Z 2020-04-23 01:32:13.197 [INF] MARKETTEST: Route for init
2020-04-23T01:42:09.4626146Z 2020-04-23 01:32:13.198 [INF] MARKETTEST: Route for redeem
2020-04-23T01:42:09.4626486Z 2020-04-23 01:32:13.198 [DBG] MARKETTEST: Locking 0 base asset coins.
2020-04-23T01:42:09.4626827Z 2020-04-23 01:32:13.198 [DBG] MARKETTEST: Locking 0 quote asset coins.
2020-04-23T01:42:09.4627288Z 2020-04-23 01:32:13.503 [INF] MARKETTEST: Sign
2020-04-23T01:42:09.4627914Z 2020-04-23 01:32:13.504 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c0000000a. Message: {"type":2,"id":1,"payload":{"result":{"sig":"","orderid":"5168ed46407d0c2cc9d320169a34aac55bb4ef55e13c27407e9d9b62dc351b8d","tserver":1587605533503}}}
2020-04-23T01:42:09.4628399Z 2020-04-23 01:32:13.504 [INF] MARKETTEST: preimage found for msg id 1: 8e6c140071db1eb2f7a18194f1a045a94c078835c75dff2f3e836180baad9e95
2020-04-23T01:42:09.4628850Z 2020-04-23 01:32:13.504 [DBG] MARKETTEST: setting preimage for order 5168ed46407d0c2cc9d320169a34aac55bb4ef55e13c27407e9d9b62dc351b8d
2020-04-23T01:42:09.4629282Z 2020-04-23 01:32:14.000 [INF] MARKETTEST: Request for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c0000000a
2020-04-23T01:42:09.4629703Z 2020-04-23 01:32:14.000 [INF] MARKETTEST: order id: 5168ed46407d0c2cc9d320169a34aac55bb4ef55e13c27407e9d9b62dc351b8d
2020-04-23T01:42:09.4630135Z 2020-04-23 01:32:14.000 [INF] MARKETTEST: found preimage: 8e6c140071db1eb2f7a18194f1a045a94c078835c75dff2f3e836180baad9e95
2020-04-23T01:42:09.4630614Z 2020-04-23 01:32:14.126 [INF] MARKETTEST: Collected 1 valid order preimages, missed 0. Commit checksum: ea0ffbc92b8575637b35137a0409d87f9ba466c732f30285eb16a827d8066de5
2020-04-23T01:42:09.4631093Z 2020-04-23 01:32:14.127 [INF] MARKETTEST: Matching complete for market dcr_btc epoch 3175211067: 0 matches (0 partial fills), 0 completed OK (not booked), 1 booked, 0 unbooked, 0 failed
2020-04-23T01:42:09.4631461Z 2020-04-23 01:32:14.174 [DBG] MARKETTEST: Market "dcr_btc" stopped.
2020-04-23T01:42:09.4632047Z 2020-04-23 01:32:14.175 [DBG] MARKETTEST: error going to user 32323463626161616661383062663362643166663733313539306263626464613561373666393165363061313536393934363334653931633030303030303036, code: 1, msg: error parsing preimage notification response: invalid type 1 for ResponsePayload
2020-04-23T01:42:09.4632672Z 2020-04-23 01:32:14.175 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006. Message: {"type":2,"id":5,"payload":{"result":null,"error":{"code":1,"message":"error parsing preimage notification response: invalid type 1 for ResponsePayload"}}}
2020-04-23T01:42:09.4633256Z 2020-04-23 01:32:14.175 [DBG] MARKETTEST: error going to user 32323463626161616661383062663362643166663733313539306263626464613561373666393165363061313536393934363334653931633030303030303036, code: 30, msg: invalid preimage length (0 byes)
2020-04-23T01:42:09.4633821Z 2020-04-23 01:32:14.175 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006. Message: {"type":2,"id":5,"payload":{"result":null,"error":{"code":30,"message":"invalid preimage length (0 byes)"}}}
2020-04-23T01:42:09.4634769Z 2020-04-23 01:32:14.176 [DBG] MARKETTEST: error going to user 32323463626161616661383062663362643166663733313539306263626464613561373666393165363061313536393934363334653931633030303030303036, code: 31, msg: preimage hash 36616236613163356364346366663861666363663830633864616230356138383534626533363230616363363431383631323036653232663066303136633661 does not match order commitment 38623565306538343561616639623663333935376539356162346161386531303763646238373366326461633532376631366334643561633837363037363861
2020-04-23T01:42:09.4635713Z 2020-04-23 01:32:14.176 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006. Message: {"type":2,"id":5,"payload":{"result":null,"error":{"code":31,"message":"preimage hash 36616236613163356364346366663861666363663830633864616230356138383534626533363230616363363431383631323036653232663066303136633661 does not match order commitment 38623565306538343561616639623663333935376539356162346161386531303763646238373366326461633532376631366334643561633837363037363861"}}}
2020-04-23T01:42:09.4636318Z 2020-04-23 01:32:14.176 [DBG] MARKETTEST: error going to user 32323463626161616661383062663362643166663733313539306263626464613561373666393165363061313536393934363334653931633030303030303036, code: 30, msg: invalid preimage length (0 byes)
2020-04-23T01:42:09.4636997Z 2020-04-23 01:32:14.176 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006. Message: {"type":2,"id":5,"payload":{"result":null,"error":{"code":30,"message":"invalid preimage length (0 byes)"}}}
2020-04-23T01:42:09.4637670Z 2020-04-23 01:32:14.177 [DBG] MARKETTEST: error going to user 32323463626161616661383062663362643166663733313539306263626464613561373666393165363061313536393934363334653931633030303030303036, code: 1, msg: error parsing preimage notification response payload result: json: cannot unmarshal number into Go value of type msgjson.PreimageResponse
2020-04-23T01:42:09.4638344Z 2020-04-23 01:32:14.177 [INF] MARKETTEST: Send for user 224cbaaafa80bf3bd1ff731590bcbdda5a76f91e60a156994634e91c00000006. Message: {"type":2,"id":5,"payload":{"result":null,"error":{"code":1,"message":"error parsing preimage notification response payload result: json: cannot unmarshal number into Go value of type msgjson.PreimageResponse"}}}
2020-04-23T01:42:09.4638560Z panic: test timed out after 10m0s
2020-04-23T01:42:09.4638626Z 
2020-04-23T01:42:09.4638777Z goroutine 84 [running]:
2020-04-23T01:42:09.4638944Z testing.(*M).startAlarm.func1()
2020-04-23T01:42:09.4639155Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:1459 +0x11c
2020-04-23T01:42:09.4639314Z created by time.goFunc
2020-04-23T01:42:09.4639531Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/time/sleep.go:168 +0x52
2020-04-23T01:42:09.4639599Z 
2020-04-23T01:42:09.4639769Z goroutine 1 [chan receive, 9 minutes]:
2020-04-23T01:42:09.4639985Z testing.(*T).Run(0xc0000a25a0, 0xbb4827, 0x13, 0xcf4980, 0x1)
2020-04-23T01:42:09.4640218Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:1043 +0x699
2020-04-23T01:42:09.4640380Z testing.runTests.func1(0xc0000a25a0)
2020-04-23T01:42:09.4640606Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:1284 +0xa7
2020-04-23T01:42:09.4640804Z testing.tRunner(0xc0000a25a0, 0xc00046b7b8)
2020-04-23T01:42:09.4641024Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:991 +0x1ec
2020-04-23T01:42:09.4641237Z testing.runTests(0xc0000a0360, 0x116e540, 0xb, 0xb, 0x0)
2020-04-23T01:42:09.4641453Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:1282 +0x528
2020-04-23T01:42:09.4641631Z testing.(*M).Run(0xc00009a180, 0x0)
2020-04-23T01:42:09.4641855Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:1199 +0x300
2020-04-23T01:42:09.4642059Z decred.org/dcrdex/server/market.TestMain.func1(0x0)
2020-04-23T01:42:09.4642274Z 	/home/runner/work/dcrdex/dcrdex/server/market/routers_test.go:510 +0x480
2020-04-23T01:42:09.4642485Z decred.org/dcrdex/server/market.TestMain(0xc00009a180)
2020-04-23T01:42:09.4642719Z 	/home/runner/work/dcrdex/dcrdex/server/market/routers_test.go:512 +0x208a
2020-04-23T01:42:09.4642862Z main.main()
2020-04-23T01:42:09.4642986Z 	_testmain.go:62 +0x224
2020-04-23T01:42:09.4643067Z 
2020-04-23T01:42:09.4643228Z goroutine 7 [select, 9 minutes]:
2020-04-23T01:42:09.4643503Z decred.org/dcrdex/server/market.(*BookRouter).runBook(0xc00009e040, 0xda9fc0, 0xc000098900, 0xc0000801e0)
2020-04-23T01:42:09.4643752Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:224 +0x268
2020-04-23T01:42:09.4644177Z decred.org/dcrdex/server/market.(*BookRouter).Run.func1(0xc00009e040, 0xda9fc0, 0xc000098900, 0xc00002a624, 0xc0000801e0)
2020-04-23T01:42:09.4644434Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:208 +0x57
2020-04-23T01:42:09.4644651Z created by decred.org/dcrdex/server/market.(*BookRouter).Run
2020-04-23T01:42:09.4644864Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:207 +0x17d
2020-04-23T01:42:09.4644952Z 
2020-04-23T01:42:09.4645117Z goroutine 18 [semacquire, 9 minutes]:
2020-04-23T01:42:09.4645272Z sync.runtime_Semacquire(0xc00002a624)
2020-04-23T01:42:09.4645486Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/runtime/sema.go:56 +0x42
2020-04-23T01:42:09.4645727Z sync.(*WaitGroup).Wait(0xc00002a624)
2020-04-23T01:42:09.4645952Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/sync/waitgroup.go:130 +0xd4
2020-04-23T01:42:09.4646203Z decred.org/dcrdex/server/market.(*BookRouter).Run(0xc00009e040, 0xda9fc0, 0xc000098900)
2020-04-23T01:42:09.4646449Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:212 +0x1a5
2020-04-23T01:42:09.4646674Z decred.org/dcrdex/server/market.TestMain.func1.1(0xc0000920f4)
2020-04-23T01:42:09.4646909Z 	/home/runner/work/dcrdex/dcrdex/server/market/routers_test.go:503 +0x99
2020-04-23T01:42:09.4647127Z created by decred.org/dcrdex/server/market.TestMain.func1
2020-04-23T01:42:09.4647342Z 	/home/runner/work/dcrdex/dcrdex/server/market/routers_test.go:502 +0x42c
2020-04-23T01:42:09.4647431Z 
2020-04-23T01:42:09.4647600Z goroutine 101 [semacquire, 9 minutes]:
2020-04-23T01:42:09.4647796Z sync.runtime_SemacquireMutex(0xc000098f0c, 0x900000000, 0x1)
2020-04-23T01:42:09.4648014Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/runtime/sema.go:71 +0x47
2020-04-23T01:42:09.4648197Z sync.(*Mutex).lockSlow(0xc000098f08)
2020-04-23T01:42:09.4648411Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/sync/mutex.go:138 +0x1c1
2020-04-23T01:42:09.4648565Z sync.(*Mutex).Lock(0xc000098f08)
2020-04-23T01:42:09.4648776Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/sync/mutex.go:81 +0x7d
2020-04-23T01:42:09.4648952Z sync.(*RWMutex).Lock(0xc000098f08)
2020-04-23T01:42:09.4649165Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/sync/rwmutex.go:98 +0x4a
2020-04-23T01:42:09.4649495Z decred.org/dcrdex/server/market.(*epochPump).Insert(0xc000098f00, 0xc000132fa0, 0xc000132fa0)
2020-04-23T01:42:09.4649714Z 	/home/runner/work/dcrdex/dcrdex/server/market/market.go:894 +0x13e
2020-04-23T01:42:09.4649941Z decred.org/dcrdex/server/market.Test_epochPump_next(0xc0000a2900)
2020-04-23T01:42:09.4650178Z 	/home/runner/work/dcrdex/dcrdex/server/market/market_test.go:1174 +0x3ed
2020-04-23T01:42:09.4650365Z testing.tRunner(0xc0000a2900, 0xcf4980)
2020-04-23T01:42:09.4650568Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:991 +0x1ec
2020-04-23T01:42:09.4650739Z created by testing.(*T).Run
2020-04-23T01:42:09.4650964Z 	/opt/hostedtoolcache/go/1.14.2/x64/src/testing/testing.go:1042 +0x661
2020-04-23T01:42:09.4651031Z 
2020-04-23T01:42:09.4651189Z goroutine 8 [select, 9 minutes]:
2020-04-23T01:42:09.4651485Z decred.org/dcrdex/server/market.(*BookRouter).runBook(0xc00009e040, 0xda9fc0, 0xc000098900, 0xc000080230)
2020-04-23T01:42:09.4651729Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:224 +0x268
2020-04-23T01:42:09.4652059Z decred.org/dcrdex/server/market.(*BookRouter).Run.func1(0xc00009e040, 0xda9fc0, 0xc000098900, 0xc00002a624, 0xc000080230)
2020-04-23T01:42:09.4652288Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:208 +0x57
2020-04-23T01:42:09.4652509Z created by decred.org/dcrdex/server/market.(*BookRouter).Run
2020-04-23T01:42:09.4652743Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:207 +0x17d
2020-04-23T01:42:09.4652812Z 
2020-04-23T01:42:09.4652972Z goroutine 9 [select, 9 minutes]:
2020-04-23T01:42:09.4653268Z decred.org/dcrdex/server/market.(*BookRouter).runBook(0xc00009e040, 0xda9fc0, 0xc000098900, 0xc000080280)
2020-04-23T01:42:09.4653509Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:224 +0x268
2020-04-23T01:42:09.4653887Z decred.org/dcrdex/server/market.(*BookRouter).Run.func1(0xc00009e040, 0xda9fc0, 0xc000098900, 0xc00002a624, 0xc000080280)
2020-04-23T01:42:09.4654143Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:208 +0x57
2020-04-23T01:42:09.4654363Z created by decred.org/dcrdex/server/market.(*BookRouter).Run
2020-04-23T01:42:09.4654593Z 	/home/runner/work/dcrdex/dcrdex/server/market/bookrouter.go:207 +0x17d
2020-04-23T01:42:09.4654660Z 
2020-04-23T01:42:09.4654826Z goroutine 102 [chan send, 9 minutes]:
2020-04-23T01:42:09.4655096Z decred.org/dcrdex/server/market.(*epochPump).next(0xc000098f00, 0xda9fc0, 0xc000098ec0, 0x0)
2020-04-23T01:42:09.4655331Z 	/home/runner/work/dcrdex/dcrdex/server/market/market.go:939 +0x2de
2020-04-23T01:42:09.4656481Z decred.org/dcrdex/server/market.(*epochPump).Run(0xc000098f00, 0xda9fc0, 0xc000098ec0)
2020-04-23T01:42:09.4656728Z 	/home/runner/work/dcrdex/dcrdex/server/market/market.go:874 +0xba
2020-04-23T01:42:09.4657047Z decred.org/dcrdex/server/market.Test_epochPump_next.func1(0xc000098f00, 0xda9fc0, 0xc000098ec0, 0xc000092570)
2020-04-23T01:42:09.4657297Z 	/home/runner/work/dcrdex/dcrdex/server/market/market_test.go:1162 +0x4d
2020-04-23T01:42:09.4657505Z created by decred.org/dcrdex/server/market.Test_epochPump_next
2020-04-23T01:42:09.4657742Z 	/home/runner/work/dcrdex/dcrdex/server/market/market_test.go:1161 +0x259
2020-04-23T01:42:09.4657831Z 
2020-04-23T01:42:09.4657982Z goroutine 52 [chan receive, 9 minutes]:
2020-04-23T01:42:09.4658275Z decred.org/dcrdex/server/market.TestMarket_enqueueEpoch.func1(0xc0000a8780, 0xc0000921e0, 0xc00000e440)
2020-04-23T01:42:09.4658521Z 	/home/runner/work/dcrdex/dcrdex/server/market/market_test.go:678 +0x66
2020-04-23T01:42:09.4658748Z created by decred.org/dcrdex/server/market.TestMarket_enqueueEpoch
2020-04-23T01:42:09.4658985Z 	/home/runner/work/dcrdex/dcrdex/server/market/market_test.go:677 +0x1105
2020-04-23T01:42:09.4659163Z FAIL	decred.org/dcrdex/server/market	600.929s
2020-04-23T01:42:09.4659358Z ok  	decred.org/dcrdex/server/market/integ	4.732s
2020-04-23T01:42:09.4659550Z ok  	decred.org/dcrdex/server/matcher	0.680s
2020-04-23T01:42:09.4659748Z ok  	decred.org/dcrdex/server/matcher/mt19937	0.045s
2020-04-23T01:42:09.4659914Z ok  	decred.org/dcrdex/server/swap	12.011s
2020-04-23T01:42:09.4660035Z FAIL
2020-04-23T01:42:09.4807520Z ##[error]Process completed with exit code 1.
2020-04-23T01:42:09.4821910Z Cleaning up orphan processes
@JoeGruffins JoeGruffins mentioned this issue Apr 23, 2020
Merged
@chappjc chappjc self-assigned this Apr 26, 2020
@chappjc
Copy link
Member

chappjc commented Apr 26, 2020

Must of the code in question is overhauled in #287, so assigning myself.

@JoeGruffins JoeGruffins mentioned this issue May 12, 2020
Closed
@chappjc
Copy link
Member

chappjc commented May 28, 2020

Out of date. Can open a new one for future problems.

@chappjc chappjc closed this as completed May 28, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@chappjc chappjc

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@chappjc @JoeGruffins