search

decred / dcrwallet

A secure Decred wallet daemon written in Go (golang).
https://decred.org
ISC License
217 stars 154 forks source link

Wallet synchronization stopped: missing credit value #1183

Closed raedah closed 5 years ago

raedah commented 6 years ago 
2018-06-17 02:10:45.891 [INF] TKBY: Not buying any tickets this round
2018-06-17 02:10:45.891 [DBG] TKBY: Purchased 0 tickets this round
2018-06-17 02:19:23.831 [INF] WLLT: Inserting unconfirmed transaction ddb0c98db4852785d42ac67147a2821c22d14daa3251f1d34a656ac6755adc15
2018-06-17 02:19:23.835 [DBG] WLLT: Marked address TsfiHKmksv5CeLqgD4mCWV4i1g9J4cShXhS used
2018-06-17 02:19:23.853 [INF] WLLT: Voted on block 000000001c8689b25b80b3090a09fd1790a90ef3a5df7e03c69d328b6ee36631 (height 326412) using ticket 39964286bb21b930752177a8b26110ba3146332b7ea5e5e3f8ad8ea7eb7603da (vote hash: ddb0c98db4852785d42ac67147a2821c22d14daa3251f1d34a656ac6755adc15 bits: 1)
2018-06-17 02:19:23.853 [DBG] WLLT: Rejected unmined orphan vote ddb0c98db4852785d42ac67147a2821c22d14daa3251f1d34a656ac6755adc15 which votes on block 000000001c8689b25b80b3090a09fd1790a90ef3a5df7e03c69d328b6ee36631
2018-06-17 02:26:28.062 [INF] WLLT: Inserting unconfirmed transaction df76b4eb31ee25a4a1d8d3f1b3ed7912f7fd9201a0a14c63b5928a5b151c0402
2018-06-17 02:26:28.062 [DBG] WLLT: Marked address TsVQe7wzQVFUDCmi1ArEgdNY5hDJVU6wfcc used
2018-06-17 02:26:28.069 [INF] WLLT: Voted on block 000000000be1f3a39178e87eeff15099bb54e848ba39e4a650d1bc617ce7211a (height 326412) using ticket 519c1a1ec5c2c421924b18954e94189fd98e100d348b953540cdd358af9cd970 (vote hash: df76b4eb31ee25a4a1d8d3f1b3ed7912f7fd9201a0a14c63b5928a5b151c0402 bits: 1)
2018-06-17 02:26:28.069 [DBG] WLLT: Rejected unmined orphan vote df76b4eb31ee25a4a1d8d3f1b3ed7912f7fd9201a0a14c63b5928a5b151c0402 which votes on block 000000000be1f3a39178e87eeff15099bb54e848ba39e4a650d1bc617ce7211a
2018-06-17 02:27:18.959 [INF] WLLT: Inserting unconfirmed transaction b3fd23e1df98168f8fba3ff180e4cafad0a5073a1d88877579ef2e2b54fde5bf
2018-06-17 02:27:18.963 [DBG] WLLT: Marked address TsSUy4HyNns2mKFtmr5ekw5NFeksMsECDFX used
2018-06-17 02:27:18.974 [INF] WLLT: Voted on block 00000000091c6d3e079d0de041831e0fca05afc52985dcb811dd627dcf6847c9 (height 326412) using ticket 7d26bb6226a50e247eda1e6214a51915f06b24d8e8bdeb343fc8058a67efbef6 (vote hash: b3fd23e1df98168f8fba3ff180e4cafad0a5073a1d88877579ef2e2b54fde5bf bits: 1)
2018-06-17 02:27:18.974 [DBG] WLLT: Rejected unmined orphan vote b3fd23e1df98168f8fba3ff180e4cafad0a5073a1d88877579ef2e2b54fde5bf which votes on block 00000000091c6d3e079d0de041831e0fca05afc52985dcb811dd627dcf6847c9
2018-06-17 02:27:33.674 [INF] WLLT: Inserting unconfirmed transaction 13a24c4ca2cab7e0aa0b4b807dd42089331de6ca900eefdbb14d79b8f8b436ee
2018-06-17 02:27:33.674 [DBG] WLLT: Marked address TsjPXApZCeHgzoqztgbGy1LuMVt1e52gkrS used
2018-06-17 02:27:33.680 [INF] WLLT: Voted on block 00000000186191c44fb9cb99f6a57c45cfe6597bb69beece47916e864afe8a5d (height 326412) using ticket 0b157b7e3a89d51e57ac82fc8a1f2b09e854473918c49297104f6680bffa9a81 (vote hash: 13a24c4ca2cab7e0aa0b4b807dd42089331de6ca900eefdbb14d79b8f8b436ee bits: 1)
2018-06-17 02:27:33.680 [DBG] WLLT: Rejected unmined orphan vote 13a24c4ca2cab7e0aa0b4b807dd42089331de6ca900eefdbb14d79b8f8b436ee which votes on block 00000000186191c44fb9cb99f6a57c45cfe6597bb69beece47916e864afe8a5d
2018-06-17 02:34:21.892 [INF] WLLT: Inserting unconfirmed transaction 5c88b1bd5bdea1ca8b871440e91c0a98abe95a22d141eaafe6e1a626b357d8ad
2018-06-17 02:34:21.895 [DBG] WLLT: Marked address TsSUy4HyNns2mKFtmr5ekw5NFeksMsECDFX used
2018-06-17 02:34:21.909 [INF] WLLT: Voted on block 00000000234784f668c21054c7fcbd087246622406b9c29c4c0b133dc36f53d1 (height 326412) using ticket 7d26bb6226a50e247eda1e6214a51915f06b24d8e8bdeb343fc8058a67efbef6 (vote hash: 5c88b1bd5bdea1ca8b871440e91c0a98abe95a22d141eaafe6e1a626b357d8ad bits: 1)
2018-06-17 02:34:21.909 [DBG] WLLT: Rejected unmined orphan vote 5c88b1bd5bdea1ca8b871440e91c0a98abe95a22d141eaafe6e1a626b357d8ad which votes on block 00000000234784f668c21054c7fcbd087246622406b9c29c4c0b133dc36f53d1
2018-06-17 02:46:44.624 [INF] WLLT: Inserting unconfirmed transaction 30125127c1c2a58c291c7ce5506cc44dab65e13d48b182a2cb0a25a5f937df2b
2018-06-17 02:46:44.624 [DBG] WLLT: Marked address TschFd63qqyKDCQHGEjVEnHhHHi8cEbYQdT used
2018-06-17 02:46:44.630 [INF] WLLT: Voted on block 000000001b2cc6db917c384a1c1784c85f6a53d046867121e3b6531884807549 (height 326412) using ticket 5c4a95dd216e74e18d1cc7bd09fa703d1d8df625c60fdef9f2de02403371733b (vote hash: 30125127c1c2a58c291c7ce5506cc44dab65e13d48b182a2cb0a25a5f937df2b bits: 1)
2018-06-17 02:46:44.631 [DBG] WLLT: Rejected unmined orphan vote 30125127c1c2a58c291c7ce5506cc44dab65e13d48b182a2cb0a25a5f937df2b which votes on block 000000001b2cc6db917c384a1c1784c85f6a53d046867121e3b6531884807549
2018-06-17 03:07:00.409 [INF] WLLT: Inserting unconfirmed transaction 5d340ac66838e5598a37e10ec9dbcc90fe26c0f5f068a10db77f57824a0e5290
2018-06-17 03:07:00.414 [DBG] WLLT: Marked address Tsbpng3SNRrZV2tnux96b5UvbfHs6WpbLFF used
2018-06-17 03:07:00.429 [INF] WLLT: Voted on block 000000000ea749bd390b742043becefa3a70a28108c5e9bbefaf4aebd08a11ff (height 326412) using ticket 6f666a264fb5ef14d06f193305376dc48d6b43a472e915952f0a32d1495a0cf0 (vote hash: 5d340ac66838e5598a37e10ec9dbcc90fe26c0f5f068a10db77f57824a0e5290 bits: 1)
2018-06-17 03:07:00.429 [DBG] WLLT: Rejected unmined orphan vote 5d340ac66838e5598a37e10ec9dbcc90fe26c0f5f068a10db77f57824a0e5290 which votes on block 000000000ea749bd390b742043becefa3a70a28108c5e9bbefaf4aebd08a11ff
2018-06-17 03:23:25.334 [INF] WLLT: Inserting unconfirmed transaction ab538d907cc31a09df1a3ff7333c6f1ef94579e950d2d685262f92aae427ae3d
2018-06-17 03:23:25.336 [DBG] WLLT: Marked address TsoPEqEAFULTLPQYoLPmzoUugj76dgfYMLP used
2018-06-17 03:23:25.350 [INF] WLLT: Voted on block 000000000786a8fa3f8269bc40f4bbd8befee86a00ee821cbbcaca4fd8ce546e (height 326412) using ticket c2304ba0f36cf62706d2f14888ceac3809dba91c49fa67fc24ca6f1daee77525 (vote hash: ab538d907cc31a09df1a3ff7333c6f1ef94579e950d2d685262f92aae427ae3d bits: 1)
2018-06-17 03:23:25.350 [DBG] WLLT: Rejected unmined orphan vote ab538d907cc31a09df1a3ff7333c6f1ef94579e950d2d685262f92aae427ae3d which votes on block 000000000786a8fa3f8269bc40f4bbd8befee86a00ee821cbbcaca4fd8ce546e
2018-06-17 03:30:22.787 [INF] WLLT: Reorganization detected!
2018-06-17 03:30:22.796 [INF] WLLT: Old top block hash: 0000000004106d3c01b5a9ee2cb690642aea700093ef1b4e4e40b47c61c90148
2018-06-17 03:30:22.796 [INF] WLLT: Old top block height: 326412
2018-06-17 03:30:22.796 [INF] WLLT: New top block hash: 00000000247702bd027335cc8412ec746d2aae92638186b987f2473c2ee50207
2018-06-17 03:30:22.796 [INF] WLLT: New top block height: 326413
2018-06-17 03:30:22.971 [INF] WLLT: Adding block 0000000014e9cfd441da66dade5b64b18edf56c467c05bb08edc59bdf46f162c (height 326412) to sidechain
2018-06-17 03:30:22.993 [INF] WLLT: Adding block 00000000247702bd027335cc8412ec746d2aae92638186b987f2473c2ee50207 (height 326413) to sidechain
2018-06-17 03:30:22.993 [DBG] WLLT: Rolling back transactions from block 0000000004106d3c01b5a9ee2cb690642aea700093ef1b4e4e40b47c61c90148 height 326412
2018-06-17 03:30:22.997 [ERR] SYNC: Wallet synchronization stopped: failed to process consensus server notification (name: `blockconnected`, detail: `missing credit value`)
2018-06-17 03:30:22.998 [INF] TKBY: Stopping ticket buyer
2018-06-17 03:30:22.998 [INF] TXMA: dcrTxClient disconnected
2018-06-17 03:30:22.998 [INF] DCRW: Attempting RPC client connection to localhost:19109
2018-06-17 03:30:23.106 [INF] SYNC: Established connection to RPC server localhost:19109
2018-06-17 03:30:23.108 [INF] TKBY: Starting ticket buyer
2018-06-17 03:30:23.108 [INF] SYNC: Wallet voting enabled: vote bits = 0x0001, extended vote bits = 06000000
2018-06-17 03:30:23.108 [INF] SYNC: Please ensure your wallet remains unlocked so it may vote
2018-06-17 03:30:23.108 [DBG] WLLT: DiscoverActiveAddresses: activeCoinType=1
2018-06-17 03:30:23.108 [INF] WLLT: Discovering used accounts
2018-06-17 03:30:32.075 [INF] WLLT: Discovering used addresses for 1 account(s)
2018-06-17 03:30:32.188 [INF] WLLT: Synchronized account 0 branch 0 to next child index 5
2018-06-17 03:30:32.193 [INF] WLLT: Synchronized account 0 branch 1 to next child index 3129
2018-06-17 03:30:32.197 [INF] WLLT: Finished address discovery
2018-06-17 03:30:32.197 [INF] WLLT: Loading active addresses and unspent outputs...
2018-06-17 03:30:32.371 [INF] WLLT: Registered for transaction notifications for 3174 address(es) and 79 output(s)
2018-06-17 03:30:32.372 [DBG] WLLT: Rolling back transactions from block 0000000004106d3c01b5a9ee2cb690642aea700093ef1b4e4e40b47c61c90148 height 326412
2018-06-17 03:30:32.372 [ERR] SYNC: Wallet synchronization stopped: missing credit value
2018-06-17 03:30:32.372 [INF] TKBY: Stopping ticket buyer
2018-06-17 03:30:32.372 [INF] TXMA: dcrTxClient disconnected
2018-06-17 03:30:32.372 [INF] DCRW: Attempting RPC client connection to localhost:19109
2018-06-17 03:30:32.397 [INF] SYNC: Established connection to RPC server localhost:19109
2018-06-17 03:30:32.398 [INF] TKBY: Starting ticket buyer
OliviaSong commented 6 years ago

anything update?

hb9xar commented 5 years ago

I just ran into a similar (the same?) issue after updating my testnet installation from GIT version Sep 24 to Nov 17. I have a voting only wallet (which seems work fine) and a staking wallet (buying the tickets) which fails during startup & sync with:

2018-11-17 21:32:32.216 [INF] DCRW: Attempting RPC client connection to localhost:19109
2018-11-17 21:32:32.311 [INF] SYNC: Established connection to RPC server localhost:19109
2018-11-17 21:32:32.314 [INF] TKBY: Starting ticket buyer
2018-11-17 21:32:32.314 [INF] SYNC: Headers synced through block 0000000007956f746403a5dfa159b501c598f70243f5d9c3ab4ad4ebe265969d height 59998
2018-11-17 21:32:32.314 [INF] SYNC: Transactions synced through block 0000000007956f746403a5dfa159b501c598f70243f5d9c3ab4ad4ebe265969d height 59998
2018-11-17 21:32:32.319 [INF] SYNC: Wallet voting enabled: vote bits = 0x0001, extended vote bits = 06000000
2018-11-17 21:32:32.319 [INF] SYNC: Please ensure your wallet remains unlocked so it may vote
2018-11-17 21:32:32.895 [INF] SYNC: Fetched 2000 new header(s) ending at height 61997 from wss://localhost:19109/ws
2018-11-17 21:32:33.247 [ERR] SYNC: Wallet synchronization stopped: rpcsyncer.Run: I/O error:: wallet.ChainSwitch: missing credit value
2018-11-17 21:32:33.247 [INF] TKBY: Stopping ticket buyer
2018-11-17 21:32:33.247 [INF] DCRW: Attempting RPC client connection to localhost:19109
2018-11-17 21:32:33.346 [INF] SYNC: Established connection to RPC server localhost:19109
2018-11-17 21:32:33.346 [ERR] SYNC: Websocket receive error from localhost:19109: websocket: close 1006 (abnormal closure): unexpected EOF
2018-11-17 21:32:33.347 [ERR] DCRW: Error connecting to RPC server: rpcclient.Start:: dcrd.jsonrpc.getcurrentnet: the client has been disconnected
2018-11-17 21:32:57.975 [INF] RPCS: RPC method walletinfo invoked by 127.0.0.1:36116
2018-11-17 21:34:51.516 [INF] RPCS: RPC method walletinfo invoked by 127.0.0.1:36126
hb9xar commented 5 years ago

In my case (see above), rebuilding teh wallet from seed did seem clear the issue I observed.

jrick commented 5 years ago

It's still not clear what is the cause of these issues. I will add additional context to the error to describe which outpoint could not be found, and that may aid in debugging if this is still an issue for new (not updated) wallets on the latest code.

jrick commented 5 years ago

This error was hit by @dajohi and I can see the problem now:

2018-12-07 12:55:21.368 [ERR] SYNC: Wallet synchronization stopped: rpcsyncer.Run: I/O error:: wallet.ChainSwitch: missing credit e57370dfea69d06ce094a7543e39331c1694e3b113cdcc22b951211378169083:6, key 83901678132151b922cccd13b1e394161c33393e54a794e06cd069eadf7073e500014b51a6e9dcc9f42449cd4eecfd6aa8a2b23c7ae7f57c5e851fc40f170ef20000000000000006, spent by 9cdbe8d0c38140fb483ecda548d44b035ea840a869ad29ff1799fe6ba2283b58

https://testnet.dcrdata.org/tx/e57370dfea69d06ce094a7543e39331c1694e3b113cdcc22b951211378169083

https://testnet.dcrdata.org/tx/9cdbe8d0c38140fb483ecda548d44b035ea840a869ad29ff1799fe6ba2283b58/in/1

https://testnet.dcrdata.org/block/00000000f20e170fc41f855e7cf5e77a3cb2a2a86afdec4ecd4924f4c9dce9a6?ind=15

The credit key contains the block hash 00000000f20e170fc41f855e7cf5e77a3cb2a2a86afdec4ecd4924f4c9dce9a6 (in unreversed form), but this is not a main chain block anymore. It seems that the key is not being correctly updated during a reorganize.

equalgeek commented 5 years ago

This is also happening on simnet Steps to replicate:

  1. Setup new simnet
  2. Create new wallet and generate new address for miningaddr
  3. start dcrd with new miningaddr
  4. start dcrwallet
  5. generate 100 new blocks via "dcrctl generate 100"
  6. getbalance on wallet and it returns 0
  7. rescanwallet then do getbalance also returns 0
  8. restarting dcrd, dcrwallet, getbalance still returns 0
  9. rebuild wallet via seed
  10. getbalance returns proper balance
jrick commented 5 years ago

@equalgeek this doesn't sound like the same issue. open a new issue if you saw that behavior running master (not the 1.3.0 release). I believe it is fixed on master and 1.4.0-rc1.

jrick commented 5 years ago

I've diagnosed this problem and will be committing a fix soon. It's not db corruption or inconsistent values in the database, but a bug in the block rollback function.