Open Alleysira opened 1 month ago
Hi there, thanks a lot for this report, you are right that the logging behavior of @ethereumjs/evm is not consistent with the other tested clients. The reason is because of how EthJS works internally, and also (partially) the way you log the output.
In EthJS, to run a single step in the EVM, there are some steps, which I will summarize with the relevant ones:
step
event (this has to be done after gas calculation to correctly report the gas cost)Due to an optimization / the internal layout of the EVM, for memory-related gas opcodes we perform the "memory expansion cost" gas calculation (which is done once the memory has to be expanded beyond the current size of memory). For instance, (in your setup), if you MSTORE to a region which the memory has not yet expanded to, we thus have to pay expansion gas. To do so, internally (so in step 1, the "gas cost calculation") we check if this expansion has to be done, and if this is the case, we also set memoryWordCount
to the value (which we expand to after running the opcode).
In your logging, you read memoryWordCount
which is thus updated before step 3 (performing the operation). However, if you would read the memory
, you will see that it is consistent.
Nevertheless, I think we should fix this, it is indeed inconsistent that in general we report the state before running the opcode, and in this case we update a variable which thus shows the state after running the opcode.
Hmm, I just realized that the memory field can also be wrong :sweat_smile: Have to think if there is an easy way to fix this or if we need a specific flag just for this logging (which will impact performance, even if there is no logger attached :sweat_smile: )
Thanks for your detailed explanation! @jochem-brouwer.
I'm afraid you are right. I added a new field data.memory
in the end of json.
var opTrace = {
'pc': data.pc,
'op': getValueByOpname(data.opcode.name),
'gas': '0x' + data.gasLeft.toString(16),
'gasCost': '0x' + data.opcode.fee.toString(16),
'memory': hexMemory,
'memSize': mem_size,
'stack': hexStack,
'depth': data.depth,
'opName': data.opcode.name,
'data.memory': data.memory // here
}
The output shows the data.memory
is also updated before the execution.
{"pc":35,"op":82,"gas":"0xfffff9","gasCost":"0x3","memory":"0x0000000000000000000000000000000000000000000000000000000000000000","memSize":32,"stack":["0x60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff","0x0"],"depth":0,"opName":"MSTORE","data.memory":{"0":0,"1":0,"2":0,"3":0,"4":0,"5":0,"6":0,"7":0,"8":0,"9":0,"10":0,"11":0,"12":0,"13":0,"14":0,"15":0,"16":0,"17":0,"18":0,"19":0,"20":0,"21":0,"22":0,"23":0,"24":0,"25":0,"26":0,"27":0,"28":0,"29":0,"30":0,"31":0}}
{"pc":42,"op":240,"gas":"0xffffea","gasCost":"0x7d00","memory":"0x60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff60ff0000000000000000000000000000000000000000000000000000000000000000","memSize":64,"stack":["0x32","0x0","0x16"],"depth":0,"opName":"CREATE","data.memory":{"0":96,"1":255,"2":96,"3":255,"4":96,"5":255,"6":96,"7":255,"8":96,"9":255,"10":96,"11":255,"12":96,"13":255,"14":96,"15":255,"16":96,"17":255,"18":96,"19":255,"20":96,"21":255,"22":96,"23":255,"24":96,"25":255,"26":96,"27":255,"28":96,"29":255,"30":96,"31":255,"32":0,"33":0,"34":0,"35":0,"36":0,"37":0,"38":0,"39":0,"40":0,"41":0,"42":0,"43":0,"44":0,"45":0,"46":0,"47":0,"48":0,"49":0,"50":0,"51":0,"52":0,"53":0,"54":0,"55":0,"56":0,"57":0,"58":0,"59":0,"60":0,"61":0,"62":0,"63":0}}
I also checked the spec. All opcodes seem to follow the steps:
Since the specification does not define when logging should begin (as it is not part of the execution), I think logging should start even before the stack check(as stack operations will alter the elements in the stack).
Anyway, thanks again!
Just checked eip-3155 from geth (even though this eip is still a draft since 2020), it says that:
The
stack
memory
andmemSize
are the values before execution of the op.
In geth implementation, the trace for memory is indeed before the expansion.
What happened
Hello developers, I'm testing
ethereumjs/evm
's with other EVM implementations. I found an inconsistency thatethereumjs/evm
will expand the memory before the expand memory related opcodes are executed, whileGeth
,Besu
andPy-EVM
don't.Just as in this example, we can observe that the memory length is already determined before the
MSTORE
operation is executed. Similarly, before theCREATE
instruction is invoked, Geth, Besu, and Py-EVM all produce the same output.Ethereumjs/evm
Geth
As I am conducting differential testing, maintaining consistent output is very important to me. I'm curious to know if there is an issue with my test script (used
step
to log run time information) or with the implementation of theethereumjs/evm
. Details will be given later.Thinks for your time!
Environment
Script
This is the script I used to run
ethereumjs/evm
:The command line to run the script:
The bytecodes in the command line consist of:
Result
As the jsons have too many rows, I have to upload json files, sorry for the trouble. gethout.json, besuout.json, pyout.json, jsout.json
Thanks for your patience!