DebugOperationTracer #10115 - 10 : storage snapshot timing #10176
Conversation
69de00e to
53f6dae
Compare
|
@macfarla Kindly take a look at once. |
macfarla
left a comment
There was a problem hiding this comment.
Critical Bug: Same pc/depth = 0 Regression as PR #10173
This PR has the same structural problem. It overrides tracePreExecution directly without calling super, and adds private fields that shadow the parent's protected ones:
// Added in child — shadows parent's protected fields:
private Optional<Bytes[]> preExecutionStack;
private long gasRemaining;
The parent's tracePreExecution (which is now bypassed) is the only place that sets pc and depth:
// AbstractDebugOperationTracer — never called anymore:
pc = frame.getPC();
depth = frame.getDepth();
The child's tracePreExecution sets preExecutionStack, gasRemaining, and inputData — but not pc or depth. Result: every trace frame reports pc=0 and depth=0. The test shouldRecordProgramCounter would catch this.
The fix is the same as for #10173: keep overriding capturePreExecutionState for inputData capture, and add a separate tracePreExecution override that calls super first then adds the SLOAD key capture:
@OverRide
public void tracePreExecution(final MessageFrame frame) {
super.tracePreExecution(frame); // sets pc, depth, traceOpcode, preExecutionStack, gasRemaining
if (traceOpcode && options.traceStorage()
&& "SLOAD".equals(frame.getCurrentOperation().getName())
&& frame.stackSize() > 0) {
preExecutionStorageKey = Optional.of(UInt256.fromBytes(frame.getStackItem(0)));
} else {
preExecutionStorageKey = Optional.empty();
}
}
@OverRide
protected void capturePreExecutionState(final MessageFrame frame) {
if (lastFrame != null && frame.getDepth() > lastFrame.getDepth())
inputData = frame.getInputData().copy();
else inputData = frame.getInputData();
}
a2d6fe8 to
26a4826
Compare
|
@macfarla please take a look . |
macfarla
left a comment
There was a problem hiding this comment.
added some comments.
preExecutionStorageKey not reset in reset()
private Optional preExecutionStorageKey = Optional.empty();
This field is not cleared in reset(). If a tracer instance is reused across transactions and tracePreExecution isn't called before captureStorage (e.g. due to an opcode filter dropping the SLOAD pre-execution call), a stale key from the previous transaction could bleed in. Add preExecutionStorageKey = Optional.empty(); to reset().
26a4826 to
f7c0ab6
Compare
macfarla
left a comment
There was a problem hiding this comment.
ok @sagarkhandagre998 this is looking pretty good now. can you add a changelog entry and then we can run the final checks
Done |
29e29bb to
ea6b501
Compare
macfarla
left a comment
There was a problem hiding this comment.
changelog entry is for a different PR
macfarla
left a comment
There was a problem hiding this comment.
changelog entry needs adjusting
de95c6b to
d55f80c
Compare
|
@macfarla Done , we can run the final checks |
macfarla
left a comment
There was a problem hiding this comment.
@sagarkhandagre998 there's a related integration test failing. Please confirm you have run these tests locally BEFORE you ask for review.
TraceTransactionIntegrationTest > shouldTraceSStoreOperation() FAILED
java.util.NoSuchElementException at TraceTransactionIntegrationTest.java:288
Per execution-apis spec (PR besu-eth#762), the storage field in debug trace struct logs must only be emitted for SLOAD and SSTORE opcodes, showing only the single slot touched by that operation. Previously, captureStorage() was called on every opcode and returned the full accumulated dirty-storage map from getUpdatedStorage(), so every frame after the first SSTORE would include all previously written slots regardless of opcode. Changes: - captureStorage() now returns Optional.empty() for all opcodes except SLOAD and SSTORE - SSTORE: uses frame.getMaybeUpdatedStorage() (set by SStoreOperation via frame.storageWasUpdated()) to return only the written slot - SLOAD: captures the slot key in tracePreExecution() before the opcode pops it off the stack, then reads the loaded value from the stack top in tracePostExecution() - Removed ModificationNotAllowedException import (no longer used) Tests: - shouldRecordStorageWhenEnabled -> split into three focused tests: shouldRecordStorageForSstoreWhenEnabled, shouldRecordStorageForSloadWhenEnabled, shouldNotRecordStorageForNonStorageOpcodeWhenEnabled - shouldCaptureFrameWhenExceptionalHaltOccurs: storage is now empty for a non-storage opcode halt (MUL), assertion updated accordingly Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com>
Per execution-apis spec (PR besu-eth#762), the storage field is only populated for SLOAD and SSTORE opcodes and contains a single-entry map for the slot touched. Update the getter and builder setter Javadoc accordingly. Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com>
…raceFrame Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com>
Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com>
Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com>
Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com>
56c9acd to
53dcd5d
Compare
Sorry for that, I didn't expect the integration failure. |
…E-only semantics TraceTransactionIntegrationTest expected storage to persist across non-storage frames (PUSH2, DUP6), which matched the old broken behaviour captureStorage() fixed in fa1c647. Update assertions so DUP6 and PUSH2 frames assert storage is empty, and only the SSTORE frame asserts the single touched slot. Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com>
6d4af4e to
ebe9425
Compare
|
Both build passes locally ./gradlew integrationTest |
You're Welcome |
…esu-eth#10176) * Fix storage snapshot timing in DebugOperationTracer Per execution-apis spec (PR besu-eth#762), the storage field in debug trace struct logs must only be emitted for SLOAD and SSTORE opcodes, showing only the single slot touched by that operation. Previously, captureStorage() was called on every opcode and returned the full accumulated dirty-storage map from getUpdatedStorage(), so every frame after the first SSTORE would include all previously written slots regardless of opcode. Changes: - captureStorage() now returns Optional.empty() for all opcodes except SLOAD and SSTORE - SSTORE: uses frame.getMaybeUpdatedStorage() (set by SStoreOperation via frame.storageWasUpdated()) to return only the written slot - SLOAD: captures the slot key in tracePreExecution() before the opcode pops it off the stack, then reads the loaded value from the stack top in tracePostExecution() - Removed ModificationNotAllowedException import (no longer used) Tests: - shouldRecordStorageWhenEnabled -> split into three focused tests: shouldRecordStorageForSstoreWhenEnabled, shouldRecordStorageForSloadWhenEnabled, shouldNotRecordStorageForNonStorageOpcodeWhenEnabled - shouldCaptureFrameWhenExceptionalHaltOccurs: storage is now empty for a non-storage opcode halt (MUL), assertion updated accordingly Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com> * Update TraceFrame storage Javadoc to reflect SLOAD/SSTORE-only semantics Per execution-apis spec (PR besu-eth#762), the storage field is only populated for SLOAD and SSTORE opcodes and contains a single-entry map for the slot touched. Update the getter and builder setter Javadoc accordingly. Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com> --------- Signed-off-by: Sagar Khandagre <sagar.khandagre998@gmail.com> Signed-off-by: abhay-dev2901 <abhaytp1998@gmail.com>
PR description
Problem
The
storagefield in debug trace struct logs was being emitted on every opcode, not just storage-touching ones. The root cause was inDebugOperationTracer.captureStorage():getUpdatedStorage()
returns "all storage slots written so far in the transaction" — it accumulates across opcodes. So once anySSTORE` executed, every subsequent frame (ADD, PUSH, JUMP, etc.) included the full dirty-storage map. This diverges from geth and the execution-apis spec, as highlighted in the ethPandaOps trace comparison report.Approach & Reasoning
The spec says: emit
storageonly forSLOADandSSTORE, showing only the single slot touched by that operation.For SSTORE this was straightforward —
SStoreOperationalready callsframe.storageWasUpdated(key, newValue)on success, which setsframe.getMaybeUpdatedStorage(). That's exactly the one slot we need. No extra tracking required.For SLOAD it was trickier.
SLoadOperationdoesn't callstorageWasUpdated(it's a read, not a write), sogetMaybeUpdatedStorage()is always empty for it. Two pieces of data are needed: the slot key and the loaded value.tracePreExecution()before the opcode runs — introducing thepreExecutionStorageKeyfield.frame.getStackItem(0)intracePostExecution()gives it directly.This approach deliberately avoids depending on
options.traceStack()being enabled — the key is captured independently of stack tracing, so storage capture works correctly regardless of what other trace flags the caller set.One edge case considered: if SLOAD halts (e.g. OOG), the value was never pushed, so the stack top would be wrong. This is guarded by checking
operationResult.getHaltReason() == nullbefore reading the stack — matching what geth does (no storage entry on a halted SLOAD).Tests
All 21 tests in
DebugOperationTracerTestpass, including the 3 new ones:shouldRecordStorageForSstoreWhenEnabled— verifies single-slot map with correct key/valueshouldRecordStorageForSloadWhenEnabled— verifies key captured pre-execution, value captured post-executionshouldNotRecordStorageForNonStorageOpcodeWhenEnabled— verifies MUL (and any non-storage opcode) emits empty storage even when `traceStorage=trueFixed Issue(s)
Refs #10115 - 10 : storage snapshot timing
Thanks for sending a pull request! Have you done the following?
doc-change-requiredlabel to this PR if updates are required.Locally, you can run these tests to catch failures early:
./gradlew spotlessApply./gradlew build./gradlew acceptanceTest./gradlew integrationTest./gradlew ethereum:referenceTests:referenceTests