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

[Lichtso]

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, fa8167a is the relevant one.

Hashes and Difference

good (mnb):

214b561 [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):

2ab4f34 [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]

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

[jeffwashington]

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]

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.