search

solana-labs / solana

Web-Scale Blockchain for fast, secure, scalable, decentralized apps and marketplaces.
https://solanalabs.com
Apache License 2.0
13.02k stars 4.19k forks source link

Consensus (bank hash) mismatch between v1.9 and v1.10/master (mainnet) #23682

Closed Lichtso closed 2 years ago

Lichtso commented 2 years ago

Problem

22102 seems to have introduced something that causes a consensus divergence in slot 124685989.

Of the three commits that were squashed and merged in that PR, https://github.com/solana-labs/solana/pull/22102/commits/fa8167a8c702442ece41bbda96708e0a383fddad is the relevant one.

Hashes and Difference

good (mnb):

214b561a286936b025deb27f00b9a942d352a3c3 [2022-03-15T19:57:36.357790216Z INFO solana_runtime::bank] bank frozen: 124685989 hash: 7BauLWcimTJ5VA59pR4nhCTCWCi22qfrb8kVFLWVPhL6 accounts_delta: Arxx1yY8Wze4xMH7eQFC4i7aHdR2vRfHK5niW8Lhyw3G signature_count: 1524 last_blockhash: 9g1Aj69xp8iYBz9pM6Lxcx8BA1PcXC34ZiHfPg4kTxJ7 capitalization: 517210598907563320

Program EWWy8ipWs2Lf4dA6CunwB2uYpevPTQUHHyiHewbwCfMp consumed 199987 of 200000 compute units

bad (master):

2ab4f34c029db5e5747dd2325379482e11a97f0a [2022-03-15T20:06:01.708041659Z INFO solana_runtime::bank] bank frozen: 124685989 hash: 7jvWuXUUwwsfbBXUA96dWrxTRg9HMqHaDYtF7DQxLiJj accounts_delta: 9KXWuzac7a4DZMUjJ3r7FH5jWFm1Wws27Ess8VAUazmS signature_count: 1524 last_blockhash: 9g1Aj69xp8iYBz9pM6Lxcx8BA1PcXC34ZiHfPg4kTxJ7 capitalization: 517210598907563320

Program EWWy8ipWs2Lf4dA6CunwB2uYpevPTQUHHyiHewbwCfMp consumed 200000 of 200000 compute units

Transaction

Entry 485 - num_hashes: 3073, hash: WYGyyAfYQ1y16r1codkyvn362iYRXqYscEZfgywtenX, transactions: 1 Transaction 0 Recent Blockhash: BmeYZnoLyJpVZKUHweL3KKWKj8Y6qdmdR2bXDotk4hSC Signature 0: 2F4xtcPQiQsULNia1iRQDJaFqfVBekLfLFAkcxp6vms4468CqLEzVw7pAGqRjSALr2BYdvyEhmBSGKtDjPUDjoyu Account 0: srw- Evcu8h19TmrxEnAiUBnAjQQQi7uKS7XZUzWPzHXvK9Pp (fee payer) Account 1: -rw- 2TgaaVoHgnSeEtXvWTx13zQeTf4hYWAMEiMQdcG6EwHi Account 2: -rw- 31cKs646dt1YkA3zPyxZ7rUAkxTBz279w4XEobFXcAKP Account 3: -rw- 6YYjGxyW7ScLJ7AbmKyAofdxuzQ3MfxnMKRNqhzvNNrt Account 4: -rw- 9qUxMSWBGAeNmXusQHuLfgSuYJqADyYoNLwZ63JJSi6V Account 5: -rw- Aqy2Pcw2SNhM4rMQbYaXE2XYsRXFejEcQfxUhUjrJDrV Account 6: -rw- Fu8q5EiFunGwSRrjFKjRUoMABj5yCoMEPccMbUiAT6PD Account 7: -r-- 98pjRuQjK3qA6gXts96PqZT4Ze5QmnCmt3QYjhbUSPue Account 8: -r-- EBDRoayCDDUvDgCimta45ajQeXbexv7aKqJubruqpyvu Account 9: -r-x EWWy8ipWs2Lf4dA6CunwB2uYpevPTQUHHyiHewbwCfMp Account 10: -r-- H6ARHf6YXhGYeQfUzQNGk6rDNnLBQKrenN712K4AQJEG Account 11: -r-- mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 Instruction 0 Program: EWWy8ipWs2Lf4dA6CunwB2uYpevPTQUHHyiHewbwCfMp (9) Account 0: mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 (11) Account 1: 98pjRuQjK3qA6gXts96PqZT4Ze5QmnCmt3QYjhbUSPue (7) Account 2: EBDRoayCDDUvDgCimta45ajQeXbexv7aKqJubruqpyvu (8) Account 3: 31cKs646dt1YkA3zPyxZ7rUAkxTBz279w4XEobFXcAKP (2) Account 4: 6YYjGxyW7ScLJ7AbmKyAofdxuzQ3MfxnMKRNqhzvNNrt (3) Account 5: Evcu8h19TmrxEnAiUBnAjQQQi7uKS7XZUzWPzHXvK9Pp (0) Account 6: 2TgaaVoHgnSeEtXvWTx13zQeTf4hYWAMEiMQdcG6EwHi (1) Account 7: Fu8q5EiFunGwSRrjFKjRUoMABj5yCoMEPccMbUiAT6PD (6) Account 8: 9qUxMSWBGAeNmXusQHuLfgSuYJqADyYoNLwZ63JJSi6V (4) Account 9: Aqy2Pcw2SNhM4rMQbYaXE2XYsRXFejEcQfxUhUjrJDrV (5) Account 10: H6ARHf6YXhGYeQfUzQNGk6rDNnLBQKrenN712K4AQJEG (10) Data: [219, 200, 88, 176, 158, 63, 253, 127, 246, 40, 92, 143, 194, 85, 84, 64, 113, 61, 10, 215, 163, 88, 84, 64, 200, 51, 104, 232, 202, 65, 229, 192, 5, 79, 236, 128, 127, 1, 0, 0]

Log

This Err(InstructionError(0, ProgramFailedToComplete)) only happens on master.

[solana_program_runtime::stable_log] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 invoke [2] [solana_program_runtime::stable_log] Program log: Mango: CancelAllPerpOrders | limit=20 [solana_program_runtime::stable_log] Program log: mango-log [solana_program_runtime::stable_log] Program log: cp1to4/ecqZ43ogDQe0xql0u2Ff66cc9XSGzkyyZdqoGDHUXDByC3VJfUNAqjqlytZh9HlwoZhJX50u7vRmUYrm6pKPh0lh5AwAAAAAAAAACAAAA1Fmr+/////+9HwAAAAAAACymVAQAAAAAzx8AAAAAAAACAAAA1Fmr+/////+9HwAAAAAAACymVAQAAAAAzx8AAAAAAAA= [solana_program_runtime::stable_log] Program log: mango-log [solana_program_runtime::stable_log] Program log: 9qpXciJ+y8R43ogDQe0xql0u2Ff66cc9XSGzkyyZdqoGDHUXDByC3VJfUNAqjqlytZh9HlwoZhJX50u7vRmUYrm6pKPh0lh5AwAAAAAAAAAAAAAAAAAAAA== [solana_bpf_loader_program] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 consumed 29586 of 134416 compute units [solana_program_runtime::stable_log] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 success [solana_program_runtime::stable_log] Program 9xQeWvG816bUx9EPjHmaT23yvVM2ZWbrrpZb9PusVFin invoke [1] [solana_program_runtime::stable_log] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 invoke [2] [solana_program_runtime::stable_log] Program log: Mango: PlacePerpOrder2 client_order_id=0 [solana_bpf_loader_program] Program 9xQeWvG816bUx9EPjHmaT23yvVM2ZWbrrpZb9PusVFin consumed 9631 of 200000 compute units [solana_program_runtime::stable_log] Program log: bid on book order_id=149916689087037453326794 quantity=6354 price=8126 [solana_bpf_loader_program] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 consumed 47818 of 100480 compute units [solana_program_runtime::stable_log] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 success [solana_program_runtime::stable_log] Program 9xQeWvG816bUx9EPjHmaT23yvVM2ZWbrrpZb9PusVFin success [solana_program_runtime::stable_log] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 invoke [2] [solana_runtime::bank] check: 1us load: 50us execute: 743us txs_len=1 [solana_program_runtime::stable_log] Program log: Mango: PlacePerpOrder2 client_order_id=0 [solana_program_runtime::stable_log] Program log: ask on book order_id=150211836992216951465526 quantity=6354 price=8143 [solana_bpf_loader_program] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 consumed 47121 of 48211 compute units [solana_program_runtime::stable_log] Program mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68 success [solana_bpf_loader_program] Program EWWy8ipWs2Lf4dA6CunwB2uYpevPTQUHHyiHewbwCfMp consumed 200000 of 200000 compute units [solana_bpf_loader_program] Program failed to complete: exceeded maximum number of instructions allowed (200000) at instruction #12281 [solana_program_runtime::stable_log] Program EWWy8ipWs2Lf4dA6CunwB2uYpevPTQUHHyiHewbwCfMp failed: Program failed to complete [solana_runtime::bank] check: 2us load: 49us execute: 853us txs_len=1 [solana_program_runtime::stable_log] Program Vote111111111111111111111111111111111111111 invoke [1] [solana_metrics::metrics] CounterPoint { name: "vote-native", count: 1, timestamp: SystemTime { tv_sec: 1647381654, tv_nsec: 405320963 } } [solana_runtime::bank] tx error: Err(InstructionError(0, ProgramFailedToComplete)) SanitizedTransaction { message: Legacy(Message { header: MessageHeader { num_required_signatures: 1, num_readonly_signed_accounts: 0, num_readonly_unsigned_accounts: 5 }, account_keys: [Evcu8h19TmrxEnAiUBnAjQQQi7uKS7XZUzWPzHXvK9Pp, 2TgaaVoHgnSeEtXvWTx13zQeTf4hYWAMEiMQdcG6EwHi, 31cKs646dt1YkA3zPyxZ7rUAkxTBz279w4XEobFXcAKP, 6YYjGxyW7ScLJ7AbmKyAofdxuzQ3MfxnMKRNqhzvNNrt, 9qUxMSWBGAeNmXusQHuLfgSuYJqADyYoNLwZ63JJSi6V, Aqy2Pcw2SNhM4rMQbYaXE2XYsRXFejEcQfxUhUjrJDrV, Fu8q5EiFunGwSRrjFKjRUoMABj5yCoMEPccMbUiAT6PD, 98pjRuQjK3qA6gXts96PqZT4Ze5QmnCmt3QYjhbUSPue, EBDRoayCDDUvDgCimta45ajQeXbexv7aKqJubruqpyvu, EWWy8ipWs2Lf4dA6CunwB2uYpevPTQUHHyiHewbwCfMp, H6ARHf6YXhGYeQfUzQNGk6rDNnLBQKrenN712K4AQJEG, mv3ekLzLbnVPNxjSKvqBpU3ZeZXPQdEC3bp5MDEBG68], recent_blockhash: BmeYZnoLyJpVZKUHweL3KKWKj8Y6qdmdR2bXDotk4hSC, instructions: [CompiledInstruction { program_id_index: 9, accounts: [11, 7, 8, 2, 3, 0, 1, 6, 4, 5, 10], data: [219, 200, 88, 176, 158, 63, 253, 127, 246, 40, 92, 143, 194, 85, 84, 64, 113, 61, 10, 215, 163, 88, 84, 64, 200, 51, 104, 232, 202, 65, 229, 192, 5, 79, 236, 128, 127, 1, 0, 0] }] }), message_hash: 6pjoTazFi7k8zqsMVWv9bwRZeNzYpatgui1UB6J8iKf1, is_simple_vote_tx: false, signatures: [2F4xtcPQiQsULNia1iRQDJaFqfVBekLfLFAkcxp6vms4468CqLEzVw7pAGqRjSALr2BYdvyEhmBSGKtDjPUDjoyu] } [solana_runtime::bank] 1 errors of 1 txs [solana_runtime::bank] store: 0us txs_len=1

Cause

As duplicate accounts were translated twice in the CPI, they were also charged for twice. And this program execution which was close to the compute meter limit got pushed over the edge.

Proposed Solution

Debug and fix.

jeffwashington commented 2 years ago

I believe this also happened on slot: 124952204

running ledger tool before and after the identified pr (2ab4f34c029db5e5747dd2325379482e11a97f0a Refactor: Remove Message and CompiledInstruction from InvokeContext interfaces (#22102)) resulted in the change to bad hash on the bank hash on that slot

jeffwashington commented 2 years ago

I believe this also happened on slot: 124952204

running ledger tool before and after the identified pr (2ab4f34 Refactor: Remove Message and CompiledInstruction from InvokeContext interfaces (#22102)) resulted in the change to bad hash on the bank hash on that slot

Confirmed that #23701 fixes the issue at this slot, too.

github-actions[bot] commented 2 years ago

This issue has been automatically locked since there has not been any activity in past 7 days after it was closed. Please open a new issue for related bugs.