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.

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

[vm] Block Pruning (Default to Only Keeping Last 768 Blocks) #436

Merged
merged 43 commits into from Sep 5, 2023

Conversation

patrick-ogrady
Copy link
Contributor

@patrick-ogrady patrick-ogrady commented Sep 1, 2023

Resolves: #130
Resolves: #302
Resolves: #448

ava-labs/avalanchego#1929

TODO

  • prevent unbounded tombstone growth (may need to force manual compaction on deleted ranges: https://github.com/cockroachdb/pebble/blob/a4fe05009372ba870cc6fe4e9b8c4873b576c549/db.go#L1693) -> can do in acceptor
    • prevent everyone from running compaction at once (add a random stutter)
  • state sync not working
    • store configurable number of blocks by height to support GetStateSummary
    • ensure GetBlockIDAtHeight returns for genesis/last accepted
  • ensure bootstrap depth config is correct
  • Increase recommended history, outside of CI, to a few thousand (protect against acceptance surge) -> need to allow reprocessing of ValidityWindow
  • Add a config not to build if too many unverified blocks
  • handle tx seen backfill with no blocks on disk?
    • if all nodes shutdown, can they recover as none will be marked ready? -> need to store validity window worth of blocks on disk? (Can infer from min block gap so don't need 2 values, can warn)
    • alternatively, could allow block building past the validity window timestamp from last accepted (would not solve problem of transitioning out of dynamic mode, which is only safe to do after accept)
    • add sync node restart where must get healthy in less than validity window
  • ensure backfill runs during normal bootstrap
    • ensure block backfill isn't off by 1
  • Set "bootstrap-retry-enabled" to false (does this prevent node from cycling when can't fetch old blocks during normal bootstrapping?)
    • does not prevent this from happening, can do from the syncervm client
[09-03|11:30:37.621] �[0;0mINFO�[0;0m <2m44aFTXtSyVpLbNCoed25Zgq1FHijFHjfAGCTwR7jw5f1vt39 Chain> vm/vm.go:501 bootstrapping started {"state sync started": true}
[09-03|11:30:37.622] INFO <2m44aFTXtSyVpLbNCoed25Zgq1FHijFHjfAGCTwR7jw5f1vt39 Chain> common/bootstrapper.go:254 bootstrapping started syncing {"numVerticesInFrontier": 1}
[09-03|11:30:37.622] INFO <2m44aFTXtSyVpLbNCoed25Zgq1FHijFHjfAGCTwR7jw5f1vt39 Chain> bootstrap/bootstrapper.go:554 executing blocks {"numPendingJobs": 0}
[09-03|11:30:37.622] INFO <2m44aFTXtSyVpLbNCoed25Zgq1FHijFHjfAGCTwR7jw5f1vt39 Chain> queue/jobs.go:224 executed operations {"numExecuted": 0}
[09-03|11:30:37.622] �[1;34mDEBUG�[0;0m <2m44aFTXtSyVpLbNCoed25Zgq1FHijFHjfAGCTwR7jw5f1vt39 Chain> vm/vm.go:873 set preference {"id": "h9tvgmhRSHEyytfJ75pQ5V4yvyuiboas8LU6usCuZBdLeSo6n"}
[09-03|11:30:37.622] INFO <2m44aFTXtSyVpLbNCoed25Zgq1FHijFHjfAGCTwR7jw5f1vt39 Chain> snowman/transitive.go:409 consensus starting {"lastAcceptedBlock": "jm2favbwcswgNQCq6aWigdu2YLsof44cxq8Yycew7iAMyA7uy"}
[09-03|11:30:37.622] �[0;0mINFO�[0;0m <2m44aFTXtSyVpLbNCoed25Zgq1FHijFHjfAGCTwR7jw5f1vt39 Chain> vm/vm.go:505 normal operation started {"state sync started": true}
  • cleanup comments to reflect memory backlog stored
    • change name of accepted cache variable to accepted depth tracking

We can process sustained 7.5k TPS (500 accts) without surpassing 2.8 GB of disk storage (all in).

vm/vm.go Outdated Show resolved Hide resolved
@patrick-ogrady patrick-ogrady marked this pull request as ready for review September 1, 2023 23:42
@patrick-ogrady
Copy link
Contributor Author

patrick-ogrady commented Sep 2, 2023

stalled with no acceptable summaries (when network wasn't producing blocks):

2023-09-01T23:51:24.6625155Z �[0;0m�[0;36m[sync] DEBUG[09-01|23:51:24.662] <C Chain> github.com/ava-labs/coreth/peer/network.go:486: adding new peer nodeID=NodeID-LTMdX2poZLv3b9NSWRh77MeZe9wnrmaJN
2023-09-01T23:51:24.6625782Z �[0;0m�[0;36m[sync] DEBUG[09-01|23:51:24.662] <C Chain> github.com/ava-labs/coreth/peer/network.go:486: adding new peer nodeID=NodeID-7cBgpXDZ7RGmVnUeFhB4w5jTgW1Pt2sSg
2023-09-01T23:51:24.6626942Z �[0;0m�[0;36m[sync] [09-01|23:51:24.662] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> sync/network_client.go:311 adding new peer {"nodeID": "NodeID-3jYX24NxPhL871mcMPtHuMtFfMFWxP6ro"}
2023-09-01T23:51:24.6628225Z �[0;0m�[0;36m[sync] [09-01|23:51:24.662] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> sync/network_client.go:311 adding new peer {"nodeID": "NodeID-LTMdX2poZLv3b9NSWRh77MeZe9wnrmaJN"}
2023-09-01T23:51:24.6629159Z �[0;0m�[0;36m[sync] [09-01|23:51:24.662] INFO <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> syncer/state_syncer.go:415 starting state sync
2023-09-01T23:51:24.6637465Z �[0;0m�[0;36m[sync] [09-01|23:51:24.663] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> sync/network_client.go:311 adding new peer {"nodeID": "NodeID-7cBgpXDZ7RGmVnUeFhB4w5jTgW1Pt2sSg"}
2023-09-01T23:51:24.6643197Z �[0;0m�[0;36m[sync] [09-01|23:51:24.664] �[0;0mINFO�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1176:TiZx3WBW2sHdvkUrEAd6z63BoTunCdp2WGquAGPtRE2BwFcNJ root=2hwLEhfQJN3awWTUijdjCRDYpXbsDTJXBdsrw6xdfJyPjDauQs"}
2023-09-01T23:51:24.6644171Z �[0;0m�[0;36m[sync] [09-01|23:51:24.664] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
2023-09-01T23:51:24.6646151Z �[0;0m�[0;36m[sync] [09-01|23:51:24.664] �[0;0mINFO�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> vm/vm.go:671 parsed block {"id": "TiZx3WBW2sHdvkUrEAd6z63BoTunCdp2WGquAGPtRE2BwFcNJ", "height": 1176}
2023-09-01T23:51:24.6647148Z �[0;0m�[0;36m[sync] [09-01|23:51:24.664] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
2023-09-01T23:51:24.6650281Z �[0;0m�[0;36m[sync] [09-01|23:51:24.664] �[0;0mINFO�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1176:TiZx3WBW2sHdvkUrEAd6z63BoTunCdp2WGquAGPtRE2BwFcNJ root=2hwLEhfQJN3awWTUijdjCRDYpXbsDTJXBdsrw6xdfJyPjDauQs"}
2023-09-01T23:51:24.6651232Z �[0;0m�[0;36m[sync] [09-01|23:51:24.664] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
2023-09-01T23:51:24.6653006Z �[0;0m�[0;36m[sync] [09-01|23:51:24.665] �[0;0mINFO�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1176:TiZx3WBW2sHdvkUrEAd6z63BoTunCdp2WGquAGPtRE2BwFcNJ root=2hwLEhfQJN3awWTUijdjCRDYpXbsDTJXBdsrw6xdfJyPjDauQs"}
2023-09-01T23:51:24.6653939Z �[0;0m�[0;36m[sync] [09-01|23:51:24.665] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
2023-09-01T23:51:24.6655743Z �[0;0m�[0;36m[sync] [09-01|23:51:24.665] �[0;0mINFO�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1176:TiZx3WBW2sHdvkUrEAd6z63BoTunCdp2WGquAGPtRE2BwFcNJ root=2hwLEhfQJN3awWTUijdjCRDYpXbsDTJXBdsrw6xdfJyPjDauQs"}
2023-09-01T23:51:24.6656676Z �[0;0m�[0;36m[sync] [09-01|23:51:24.665] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
2023-09-01T23:51:24.6657857Z �[0;0m�[0;36m[sync] [09-01|23:51:24.665] �[0;0mINFO�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1176:TiZx3WBW2sHdvkUrEAd6z63BoTunCdp2WGquAGPtRE2BwFcNJ root=2hwLEhfQJN3awWTUijdjCRDYpXbsDTJXBdsrw6xdfJyPjDauQs"}
2023-09-01T23:51:24.6658765Z �[0;0m�[0;36m[sync] [09-01|23:51:24.665] �[1;34mDEBUG�[0;0m <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
2023-09-01T23:51:24.6664527Z �[0;0m�[0;36m[sync] [09-01|23:51:24.666] INFO <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> syncer/state_syncer.go:302 skipping state sync {"reason": "no acceptable summaries found"}
2023-09-01T23:51:24.6665351Z �[0;0m�[0;36m[sync] [09-01|23:51:24.666] INFO <irBg7W9jLWZZUe3vwnZQT1myDddT3tCUhA4NdZEKAZhMcwfQE Chain> bootstrap/bootstrapper.go:115 starting bootstrapper

@patrick-ogrady
Copy link
Contributor Author

[09-01|17:17:58.353] INFO <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> syncer/state_syncer.go:415 starting state sync
[09-01|17:17:58.354] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "connected"}
[09-01|17:17:58.354] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-F5eqgfi8FyMjn8UHACxddwiCzHTMHsRAh", "messageOp": "connected"}
[09-01|17:17:58.354] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "connected"}
[09-01|17:17:58.354] �[1;34mDEBUG�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> sync/network_client.go:311 adding new peer {"nodeID": "NodeID-F5eqgfi8FyMjn8UHACxddwiCzHTMHsRAh"}
[09-01|17:17:58.355] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-GrH5eahYJ82aSw23UGa3dgjRZARoRagBT", "messageOp": "state_summary_frontier"}
[09-01|17:17:58.356] �[0;0mINFO�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1178:bRuqsHvaZVfBZFaKnzzeXGg6NPVjhc9PJHmeSrjUCwiQhDYVz root=2oSMqnrAqDdgCX14NKwN628xPpM7E2cQwvDHkbgnN2P4gkkhNH"}
[09-01|17:17:58.356] �[1;34mDEBUG�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
[09-01|17:17:58.356] �[0;0mINFO�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> vm/vm.go:671 parsed block {"id": "bRuqsHvaZVfBZFaKnzzeXGg6NPVjhc9PJHmeSrjUCwiQhDYVz", "height": 1178}
[09-01|17:17:58.356] �[1;34mDEBUG�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
[09-01|17:17:58.356] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "state_summary_frontier"}
[09-01|17:17:58.356] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-F5eqgfi8FyMjn8UHACxddwiCzHTMHsRAh", "messageOp": "state_summary_frontier"}
[09-01|17:17:58.356] �[0;0mINFO�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1178:bRuqsHvaZVfBZFaKnzzeXGg6NPVjhc9PJHmeSrjUCwiQhDYVz root=2oSMqnrAqDdgCX14NKwN628xPpM7E2cQwvDHkbgnN2P4gkkhNH"}
[09-01|17:17:58.357] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "state_summary_frontier"}
[09-01|17:17:58.357] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-DL1cPFJJUqw6hVNqeNH1zAoBEc3qtu9KS", "messageOp": "state_summary_frontier"}
[09-01|17:17:58.357] �[1;34mDEBUG�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
[09-01|17:17:58.357] �[0;0mINFO�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1178:bRuqsHvaZVfBZFaKnzzeXGg6NPVjhc9PJHmeSrjUCwiQhDYVz root=2oSMqnrAqDdgCX14NKwN628xPpM7E2cQwvDHkbgnN2P4gkkhNH"}
[09-01|17:17:58.357] �[1;34mDEBUG�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
[09-01|17:17:58.357] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "state_summary_frontier"}
[09-01|17:17:58.357] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-5zYPfX6H9PdhfpS9rSMK7Pid5ckGi54ZL", "messageOp": "state_summary_frontier"}
[09-01|17:17:58.357] �[0;0mINFO�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1178:bRuqsHvaZVfBZFaKnzzeXGg6NPVjhc9PJHmeSrjUCwiQhDYVz root=2oSMqnrAqDdgCX14NKwN628xPpM7E2cQwvDHkbgnN2P4gkkhNH"}
[09-01|17:17:58.357] �[1;34mDEBUG�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
[09-01|17:17:58.357] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "state_summary_frontier"}
[09-01|17:17:58.358] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-68RMir7gMa8toWodJFdZsLbggGhpW6p19", "messageOp": "state_summary_frontier"}
[09-01|17:17:58.358] �[0;0mINFO�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> vm/syncervm_server.go:47 parsed state summary {"summary": "1178:bRuqsHvaZVfBZFaKnzzeXGg6NPVjhc9PJHmeSrjUCwiQhDYVz root=2oSMqnrAqDdgCX14NKwN628xPpM7E2cQwvDHkbgnN2P4gkkhNH"}
[09-01|17:17:58.358] �[1;34mDEBUG�[0;0m <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> chain/auth_batch.go:66 enqueued batch for processing during done
[09-01|17:17:58.358] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> syncer/state_syncer.go:525 sent GetAcceptedStateSummary messages {"numSent": 5, "numPending": 0}
[09-01|17:17:58.358] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "state_summary_frontier"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-DL1cPFJJUqw6hVNqeNH1zAoBEc3qtu9KS", "messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-68RMir7gMa8toWodJFdZsLbggGhpW6p19", "messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-GrH5eahYJ82aSw23UGa3dgjRZARoRagBT", "messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-F5eqgfi8FyMjn8UHACxddwiCzHTMHsRAh", "messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:480 finished handling sync message {"messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> handler/handler.go:459 forwarding sync message to consensus {"nodeID": "NodeID-5zYPfX6H9PdhfpS9rSMK7Pid5ckGi54ZL", "messageOp": "accepted_state_summary"}
[09-01|17:17:58.359] DEBUG <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> syncer/state_syncer.go:271 removing summary {"reason": "insufficient weight", "currentWeight": 0, "requiredWeight": 2501}
[09-01|17:17:58.359] INFO <MqNfEpF5Uc8kQDjCFU3aQvCFXVi7UQEkm9c7YeNoBim3kkZCE Chain> syncer/state_syncer.go:302 skipping state sync {"reason": "no acceptable summaries found"}

@patrick-ogrady patrick-ogrady marked this pull request as draft September 2, 2023 00:26
README.md Outdated Show resolved Hide resolved
@patrick-ogrady
Copy link
Contributor Author

patrick-ogrady commented Sep 4, 2023

Error on E2E:

[bootstrap] [09-04|10:21:26.006] INFO <2MuTPJMq2Fzb4ujtoc2zke9YpyWW1Ckd855gkMiPQJaMHYKsCE Chain> chain/block.go:803 block not processed {"height": 135, "blkID": "3mXucbK8NwV51fzTGdgGonoyjFzNgp7CxBHHxojxjNmCGv97s", "attemptVerify": true}
[bootstrap] [09-04|10:21:26.006] INFO <2MuTPJMq2Fzb4ujtoc2zke9YpyWW1Ckd855gkMiPQJaMHYKsCE Chain> chain/block.go:839 block root does not match accepted state {"height": 135, "blkID": "3mXucbK8NwV51fzTGdgGonoyjFzNgp7CxBHHxojxjNmCGv97s", "accepted root": "28ZicU6EuLXYU797BvfpCHu1GZp2ZVxLDbA7S9rzXQq2ySt3CC", "block root": "2tNGqHJ7DFZYkTzRkoxduntDXBrCMCQarsmV1QHEyJ7vGMHdmw"}
[bootstrap] [09-04|10:21:26.006] INFO <2MuTPJMq2Fzb4ujtoc2zke9YpyWW1Ckd855gkMiPQJaMHYKsCE Chain> chain/block.go:855 verifying block when view requested {"height": 135, "blkID": "3mXucbK8NwV51fzTGdgGonoyjFzNgp7CxBHHxojxjNmCGv97s", "accepted": false}
[bootstrap] [09-04|10:21:26.006] ERROR <2MuTPJMq2Fzb4ujtoc2zke9YpyWW1Ckd855gkMiPQJaMHYKsCE Chain> chain/block.go:866 unable to verify block {"error": "duplicate transaction: duplicate in ancestry"}
[bootstrap] [09-04|10:21:26.007] DEBUG <2MuTPJMq2Fzb4ujtoc2zke9YpyWW1Ckd855gkMiPQJaMHYKsCE Chain> snowman/transitive.go:886 block verification failed {"error": "rpc error: code = Unknown desc = duplicate transaction: duplicate in ancestry: unable to load parent view"}

Not setting accepted status following state sync 🤦

@patrick-ogrady patrick-ogrady marked this pull request as ready for review September 4, 2023 17:41
return err
}
vm.preferred, vm.lastAccepted = blk.ID(), blk
if err := vm.loadAcceptedBlocks(ctx); err != nil {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because we store the AcceptedBlockWindow in memory, we don't need an index of BlockID -> Height/Block.

@patrick-ogrady patrick-ogrady changed the title [vm] Only Store Last Accepted Block on Disk [vm] Block Pruning Sep 4, 2023
@patrick-ogrady patrick-ogrady changed the title [vm] Block Pruning [vm] Block Pruning (Default to Only Keeping Last 768 Blocks) Sep 4, 2023
return
}

// Exit early if we don't have any blocks other than genesis (which
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Turns out this backfill was not being triggered in a number of cases where it should have. I moved to vm to trigger during ANY bootstrap.

@patrick-ogrady
Copy link
Contributor Author

patrick-ogrady commented Sep 4, 2023

Odd that pebble size continues to increase (should be much smaller than this):

2.1G	./chainData/nDv8b2SNcXZPj1JgVc53HVD2Qy4j2Dp8j9UpGQTJ5xfrEkfL3/blockdb
 70M	./chainData/nDv8b2SNcXZPj1JgVc53HVD2Qy4j2Dp8j9UpGQTJ5xfrEkfL3/statedb
 12K	./chainData/nDv8b2SNcXZPj1JgVc53HVD2Qy4j2Dp8j9UpGQTJ5xfrEkfL3/metadatadb
2.2G	./chainData/nDv8b2SNcXZPj1JgVc53HVD2Qy4j2Dp8j9UpGQTJ5xfrEkfL3
  0B	./chainData/11111111111111111111111111111111LpoYY

... doesn't seem like deletion is actually occurring

@patrick-ogrady
Copy link
Contributor Author

patrick-ogrady commented Sep 5, 2023

Cause for this is that PebbleDB uses tombstones instead of actively deleting data (growing unbounded):
image

WAL is being limited at ~100MB:
image

@abi87 abi87 self-assigned this Sep 5, 2023
@patrick-ogrady patrick-ogrady merged commit fa48f6e into main Sep 5, 2023
20 checks passed
@patrick-ogrady patrick-ogrady deleted the delete-blocks branch September 5, 2023 20:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
3 participants