mimblewimble / grin

Minimal implementation of the Mimblewimble protocol.
https://grin.mw/
Apache License 2.0
5.04k stars 990 forks source link

Could not compact chain LMDB Error #1631

Closed quentinlesceller closed 6 years ago

quentinlesceller commented 6 years ago

Attaching part of the log.

Sep 29 06:55:01.674 DEBG Received block 1a650b35 at 116000 from 204.48.26.36:13414, inputs: 0, outputs: 1, kernels: 1, going to process.
Sep 29 06:55:01.675 DEBG pipe: process_block 1a650b35 at 116000 with 0 inputs, 1 outputs, 1 kernels
Sep 29 06:55:01.676 DEBG lru_verifier_cache: rangeproofs: 1, not cached (must verify): 1
Sep 29 06:55:01.681 DEBG lru_verifier_cache: kernel sigs: 1, not cached (must verify): 1
Sep 29 06:55:01.703 DEBG pipe: chain head 1a650b35 @ 116000
Sep 29 06:55:01.708 DEBG adapter: block_accepted: 1a650b35
Sep 29 06:55:01.708 DEBG Send header 1a650b35 to 195.201.38.140:13414
Sep 29 06:55:01.709 DEBG Send header 1a650b35 to 198.245.50.26:13414
Sep 29 06:55:01.710 DEBG Send header 1a650b35 to 95.216.163.175:13414
Sep 29 06:55:01.711 DEBG Send header 1a650b35 to 8.6.8.66:13414
Sep 29 06:55:01.711 DEBG Send header 1a650b35 to 46.4.91.48:13414
Sep 29 06:55:01.712 DEBG Send header 1a650b35 to 109.74.202.16:13414
Sep 29 06:55:01.713 DEBG Received block header 1a650b35 at 116000 from 95.216.163.175:13414, going to process.
Sep 29 06:55:01.714 DEBG pipe: process_block_header at 116000 [1a650b35]
Sep 29 06:55:01.714 DEBG Block header 1a650b35 refused by chain: Unfit("already known")
Sep 29 06:55:01.714 DEBG Starting blockchain compaction.
Sep 29 06:55:01.752 DEBG Received block header 1a650b35 at 116000 from 195.201.38.140:13414, going to process.
Sep 29 06:55:01.753 DEBG pipe: process_block_header at 116000 [1a650b35]
Sep 29 06:55:01.754 DEBG Block header 1a650b35 refused by chain: Unfit("already known")
Sep 29 06:55:02.573 DEBG -- outputs --
Sep 29 06:55:02.574 DEBG --
Sep 29 06:55:02.575 DEBG pmmr: unpruned - 259051
Sep 29 06:55:02.576 DEBG pmmr backend: unpruned: 259051, hashes: 212689, data: 99590, leaf_set: 87781, prune_list: 18562
Sep 29 06:55:02.576 DEBG -- end of outputs --
Sep 29 06:55:02.578 DEBG txhashset: merkle_proof: output: Commitment(08c5589877757a1db9cc22a15cd0236c01ff3bf0e2d32f5ef8bba21f4f3e75b7e2), block: 0c03007f
Sep 29 06:55:02.579 DEBG merkle_proof  259048, last_pos 259048
Sep 29 06:55:02.580 DEBG Validating state after compaction.
Sep 29 06:55:03.005 DEBG txhashset: validated the output 259051, rproof 259051, kernel 242048 mmrs, took 0s
Sep 29 06:55:05.893 DEBG monitor_peers: on 0.0.0.0:13414, 7 connected (5 most_work). all 638 = 7 healthy + 0 banned + 631 defunct
Sep 29 06:55:05.894 DEBG monitor_peers: 0.0.0.0:13414 ask 195.201.38.140:13414 for more peers
Sep 29 06:55:05.894 DEBG Asking 195.201.38.140:13414 for more peers.
Sep 29 06:55:05.895 DEBG monitor_peers: 0.0.0.0:13414 ask 109.74.202.16:13414 for more peers
Sep 29 06:55:05.896 DEBG Asking 109.74.202.16:13414 for more peers.
Sep 29 06:55:05.897 DEBG monitor_peers: 0.0.0.0:13414 ask 198.245.50.26:13414 for more peers
Sep 29 06:55:05.897 DEBG Asking 198.245.50.26:13414 for more peers.
Sep 29 06:55:05.897 DEBG monitor_peers: 0.0.0.0:13414 ask 204.48.26.36:13414 for more peers
Sep 29 06:55:05.897 DEBG Asking 204.48.26.36:13414 for more peers.
Sep 29 06:55:05.897 DEBG monitor_peers: 0.0.0.0:13414 ask 8.6.8.66:13414 for more peers
Sep 29 06:55:05.897 DEBG Asking 8.6.8.66:13414 for more peers.
Sep 29 06:55:05.897 DEBG monitor_peers: 0.0.0.0:13414 ask 46.4.91.48:13414 for more peers
Sep 29 06:55:05.898 DEBG Asking 46.4.91.48:13414 for more peers.
Sep 29 06:55:05.898 DEBG monitor_peers: 0.0.0.0:13414 ask 95.216.163.175:13414 for more peers
Sep 29 06:55:05.898 DEBG Asking 95.216.163.175:13414 for more peers.
Sep 29 06:55:05.898 DEBG monitor_peers: no preferred peers
Sep 29 06:55:05.898 DEBG monitor_peers: updating expired dandelion relay
Sep 29 06:55:05.898 DEBG Successfully updated Dandelion relay to: 46.4.91.48:13414
Sep 29 06:55:25.896 DEBG monitor_peers: on 0.0.0.0:13414, 7 connected (5 most_work). all 638 = 7 healthy + 0 banned + 631 defunct
Sep 29 06:55:25.896 DEBG monitor_peers: 0.0.0.0:13414 ask 46.4.91.48:13414 for more peers
Sep 29 06:55:25.897 DEBG Asking 46.4.91.48:13414 for more peers.
Sep 29 06:55:25.898 DEBG monitor_peers: 0.0.0.0:13414 ask 198.245.50.26:13414 for more peers
Sep 29 06:55:25.899 DEBG Asking 198.245.50.26:13414 for more peers.
Sep 29 06:55:25.900 DEBG monitor_peers: 0.0.0.0:13414 ask 204.48.26.36:13414 for more peers
Sep 29 06:55:25.900 DEBG Asking 204.48.26.36:13414 for more peers.
Sep 29 06:55:25.900 DEBG monitor_peers: 0.0.0.0:13414 ask 195.201.38.140:13414 for more peers
Sep 29 06:55:25.900 DEBG Asking 195.201.38.140:13414 for more peers.
Sep 29 06:55:25.900 DEBG monitor_peers: 0.0.0.0:13414 ask 109.74.202.16:13414 for more peers
Sep 29 06:55:25.900 DEBG Asking 109.74.202.16:13414 for more peers.
Sep 29 06:55:25.900 DEBG monitor_peers: 0.0.0.0:13414 ask 8.6.8.66:13414 for more peers
Sep 29 06:55:25.900 DEBG Asking 8.6.8.66:13414 for more peers.
Sep 29 06:55:25.900 DEBG monitor_peers: 0.0.0.0:13414 ask 95.216.163.175:13414 for more peers
Sep 29 06:55:25.900 DEBG Asking 95.216.163.175:13414 for more peers.
Sep 29 06:55:25.900 DEBG monitor_peers: no preferred peers
Sep 29 06:55:33.119 DEBG txhashset: verified 121028 kernel signatures, pmmr size 242048, took 27s
Sep 29 06:55:33.121 DEBG txhashset: merkle_proof: output: Commitment(08c5589877757a1db9cc22a15cd0236c01ff3bf0e2d32f5ef8bba21f4f3e75b7e2), block: 0c03007f
Sep 29 06:55:33.122 DEBG merkle_proof  259048, last_pos 259048
Sep 29 06:55:33.123 DEBG Compaction remove blocks older than 113120.
Sep 29 06:55:33.514 ERRO Could not compact chain: Error { inner: LmdbErr(Error::Code(-30798, 'MDB_NOTFOUND: No matching key/data pair found'))

Store Error: LmdbErr(Error::Code(-30798, 'MDB_NOTFOUND: No matching key/data pair found')) }
Sep 29 06:55:34.836 DEBG handle_payload: received compact block: msg_len: 1268
Sep 29 06:55:34.836 DEBG Received compact_block 05c9f0c9 at 116002 from 204.48.26.36:13414, outputs: 1, kernels: 1, kern_ids: 0, going to process.
Sep 29 06:55:34.837 DEBG pipe: process_block 05c9f0c9 at 116002 with 0 inputs, 1 outputs, 1 kernels
ignopeverell commented 6 years ago

It'd be nice if @antiochp could confirm but I'm strongly suspecting the block sums deletion on compact is the culprit. This has been added recently so you wouldn't have as much history as for blocks. And lmdb_zero does return a MDB_NOTFOUND if the key to delete isn't found.

TL;DR ignore, will go away.

antiochp commented 6 years ago

Oh are we not checking for existence of these before deleting (and we assume they exist)? Or not just ignoring these errors? Let me check and confirm.

Edit: yes that's the issue. We can easily make this a little more robust, but yes, it will go away over time and is safe to ignore.

antiochp commented 6 years ago

(This is assuming this was a recently upgraded node that had been running with old code and no block_sums).