search

decred / dcrdex

The Decred Decentralized Exchange (DEX), powered by atomic-swaps.
Other
187 stars 96 forks source link

simnet/dcr: tip report channel was blocking #2971

Closed JoeGruffins closed 1 month ago

JoeGruffins commented 2 months ago

I've seen this a couple times now testing on simnet recently. Unsure if it is only a simnet thing. I create a new bisonw on simnet and send it funds. However the wallet will not show the funds and I get the warning CORE[dcr][SPV]: tip report channel was blocking It does not happen all the time.

On ae2fbd0eb2dd56eadf5095c21c663957fb083a26

2024-09-12 05:18:06.613 [WRN] CORE[dcr][SPV]: tip report channel was blocking
2024-09-12 05:18:08.316 [TRC] CORE[btc]: tip change: 473 (128158ca4518ba3aeddc7099e6d52b303272bfe09fa1584e643bdf80f403796f) => 474 (70975f27176e1047544001dd4ed3bea5d593ccb8324c0f1da18839f98015e57b)
2024-09-12 05:18:08.316 [TRC] CORE: Processing tip change for btc
2024-09-12 05:18:08.316 [TRC] CORE[btc][SPV]: Bals: spendable = 100 BTC (100 BTC trusted, 0 BTC untrusted, 0 BTC assumed locked), immature = 0 BTC
2024-09-12 05:18:21.114 [TRC] CORE[eth][RPC]: Fetching fresh header from "IPC"
2024-09-12 05:18:21.115 [TRC] CORE[eth]: tip change: 136 (0x21bafcfcab9e6bc872817db1f1003a491f2c69e6af6638c67d547b2f26002748) => 139 (0xab296068f6c8f3c564f08c68ad3774cb02ecf12964f54048854d4644cf489ee8)
2024-09-12 05:18:21.115 [TRC] CORE: Processing tip change for eth
2024-09-12 05:18:22.194 [WRN] CORE[dcr][SPV]: tip report channel was blocking
2024-09-12 05:18:23.325 [TRC] CORE[btc]: tip change: 474 (70975f27176e1047544001dd4ed3bea5d593ccb8324c0f1da18839f98015e57b) => 475 (311ec844fc7877363fb1fadb717183db4a2187a33be51884f58c3ef48b9e14cd)
2024-09-12 05:18:23.325 [TRC] CORE: Processing tip change for btc
2024-09-12 05:18:23.325 [TRC] CORE[btc][SPV]: Bals: spendable = 100 BTC (100 BTC trusted, 0 BTC untrusted, 0 BTC assumed locked), immature = 0 BTC
2024-09-12 05:18:29.890 [TRC] MUX: "POST http://127.0.0.3:5758/api/orders HTTP/1.1" from 127.0.0.1:60784 - 200 24B in 116.468µs
2024-09-12 05:18:29.892 [TRC] MUX: "POST http://127.0.0.3:5758/api/mixingstats HTTP/1.1" from 127.0.0.1:60788 - 200 103B in 95.078µs
2024-09-12 05:18:31.248 [TRC] MUX: "POST http://127.0.0.3:5758/api/walletsettings HTTP/1.1" from 127.0.0.1:60788 - 200 40B in 98.134µs
2024-09-12 05:18:31.251 [TRC] MUX: "POST http://127.0.0.3:5758/api/orders HTTP/1.1" from 127.0.0.1:60788 - 200 24B in 67.777µs
2024-09-12 05:18:32.134 [TRC] MUX: "POST http://127.0.0.3:5758/api/orders HTTP/1.1" from 127.0.0.1:60788 - 200 24B in 88.185µs
2024-09-12 05:18:32.136 [TRC] MUX: "POST http://127.0.0.3:5758/api/mixingstats HTTP/1.1" from 127.0.0.1:41092 - 200 103B in 70.713µs
2024-09-12 05:18:33.106 [TRC] MUX: "POST http://127.0.0.3:5758/api/orders HTTP/1.1" from 127.0.0.1:41092 - 200 24B in 83.046µs
2024-09-12 05:18:33.581 [TRC] MUX: "POST http://127.0.0.3:5758/api/orders HTTP/1.1" from 127.0.0.1:41092 - 200 24B in 79.288µs
2024-09-12 05:18:33.583 [TRC] MUX: "POST http://127.0.0.3:5758/api/mixingstats HTTP/1.1" from 127.0.0.1:41098 - 200 103B in 103.985µs
2024-09-12 05:18:36.114 [TRC] CORE[eth][RPC]: Fetching fresh header from "IPC"
2024-09-12 05:18:36.115 [TRC] CORE[eth]: tip change: 139 (0xab296068f6c8f3c564f08c68ad3774cb02ecf12964f54048854d4644cf489ee8) => 141 (0x866ce41bebd467c46bfc58c7b983fa062e6aaf02c6d4cc63933ea641cad14520)
2024-09-12 05:18:36.115 [TRC] CORE: Processing tip change for eth
2024-09-12 05:18:37.782 [WRN] CORE[dcr][SPV]: tip report channel was blocking

When closing bisonw with ctrl-c:

2024-09-12 05:22:59.271 [ERR] CORE: Failed to lock DCR wallet: timeout
2024-09-12 05:22:59.271 [INF] CORE[dcr][SPV]: Unloading wallet
2024-09-12 05:22:59.271 [INF] CORE[dcr][SPV]: SPV wallet closed

But it hangs anyway and does not shutdown properly. Everything seems fine upon starting for the second time. May just be a new wallet.

buck54321 commented 2 months ago

This is familiar. I think we're mishandling a context.Context somewhere.

JoeGruffins commented 1 month ago

Saw something similar on mainnet with dcr rpc. This was blocking a refund:

2024-09-29 06:56:31.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 06:57:54.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:02:02.842 [DBG] CORE: Expired bond xxx (dcr) refundable in about 388h0m17s.
2024-09-29 07:03:33.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:04:32.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:10:10.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:11:17.633 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:13:32.631 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:19:19.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:26:13.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:32:02.842 [DBG] CORE: Expired bond xxx (dcr) refundable in about 387h30m17s.
2024-09-29 07:36:07.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:36:21.631 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:48:03.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:52:40.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 07:58:54.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 08:01:52.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 08:02:02.842 [DBG] CORE: Expired bond xxx (dcr) refundable in about 387h0m17s.
2024-09-29 08:02:21.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 08:06:45.631 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 08:07:02.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 08:11:00.632 [WRN] CORE[dcr]: blocking WalletNotification channel
2024-09-29 08:15:53.633 [WRN] CORE[dcr]: blocking WalletNotification channel