towards a standard EVM trace format #249

cdetrio · 2017-08-04T20:45:17Z

Towards a standard EVM trace format

The purpose of this standard trace format is to facilitate automated equivalence testing of different EVM implementations.

steps are logged with the state of the environment (stack, gas remaining, program counter, etc.) immediately before execution of the opcode.
call stack depth starts at zero

Temporary workarounds

steps that result in exceptions (e.g. OOG exceptions) are logged as if they were successful
- except for invalid opcode exceptions, which are not logged
  - invalid opcode exception is easy to check for before execution
  - it is easier to remove them from the log than to converge on a standard error code
- it is useful to see in a trace the operation that caused an OOG exception, or a stack underflow, etc.
- but it complicates the tracing logic if the result of an operation needs to be known before it is logged

Noted quirks

geth logs STOP operations on all successful exits, even when there is no STOP opcode. For example, where pyethereum logs:

TRACE:eth.vm.op	{"event": "eth.vm.op.vm", "level": "TRACE", "op": "SSTORE", "stack": ["b'133001'", "b'2'"], "gas": "b'20030'", "inst": 85, "pc": "b'72'", "steps": 32, "depth": 132}
TRACE:eth.vm.exit {"event": "eth.vm.exit.exit", "level": "TRACE", "cause": "CODE OUT OF RANGE"}

geth will log:

{"pc":72,"op":85,"gas":"0x4e3e","gasCost":"0x4e20","memory":"0x","memSize":0,"stack":["0x20789","0x2"],"depth":133,"error":null,"opName":"SSTORE"}
{"pc":73,"op":0,"gas":"0x1e","gasCost":"0x0","memory":"0x","memSize":0,"stack":[],"depth":133,"error":null,"opName":"STOP"}

Example trace

This trace is produced by executing the stCallCodes/callcall_00 state test.

{'pc': 0, 'op': 96, 'gas': '0x2d74b8', 'gasCost': '0x3', 'stack': [], 'depth': 0, 'opName': 'PUSH1'}
{'pc': 2, 'op': 96, 'gas': '0x2d74b5', 'gasCost': '0x3', 'stack': ['0x40'], 'depth': 0, 'opName': 'PUSH1'}
{'pc': 4, 'op': 96, 'gas': '0x2d74b2', 'gasCost': '0x3', 'stack': ['0x40', '0x0'], 'depth': 0, 'opName': 'PUSH1'}
{'pc': 6, 'op': 96, 'gas': '0x2d74af', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40'], 'depth': 0, 'opName': 'PUSH1'}
{'pc': 8, 'op': 96, 'gas': '0x2d74ac', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40', '0x0'], 'depth': 0, 'opName': 'PUSH1'}
{'pc': 10, 'op': 115, 'gas': '0x2d74a9', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40', '0x0', '0x1'], 'depth': 0, 'opName': 'PUSH20'}
{'pc': 31, 'op': 98, 'gas': '0x2d74a6', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40', '0x0', '0x1', '0x1000000000000000000000000000000000000001'], 'depth': 0, 'opName': 'PUSH3'}
{'pc': 35, 'op': 241, 'gas': '0x2d74a3', 'gasCost': '0x57d1a', 'stack': ['0x40', '0x0', '0x40', '0x0', '0x1', '0x1000000000000000000000000000000000000001', '0x55730'], 'depth': 0, 'opName': 'CALL'}
{'pc': 0, 'op': 96, 'gas': '0x5602c', 'gasCost': '0x3', 'stack': [], 'depth': 1, 'opName': 'PUSH1'}
{'pc': 2, 'op': 96, 'gas': '0x56029', 'gasCost': '0x3', 'stack': ['0x40'], 'depth': 1, 'opName': 'PUSH1'}
{'pc': 4, 'op': 96, 'gas': '0x56026', 'gasCost': '0x3', 'stack': ['0x40', '0x0'], 'depth': 1, 'opName': 'PUSH1'}
{'pc': 6, 'op': 96, 'gas': '0x56023', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40'], 'depth': 1, 'opName': 'PUSH1'}
{'pc': 8, 'op': 96, 'gas': '0x56020', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40', '0x0'], 'depth': 1, 'opName': 'PUSH1'}
{'pc': 10, 'op': 115, 'gas': '0x5601d', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40', '0x0', '0x2'], 'depth': 1, 'opName': 'PUSH20'}
{'pc': 31, 'op': 98, 'gas': '0x5601a', 'gasCost': '0x3', 'stack': ['0x40', '0x0', '0x40', '0x0', '0x2', '0x1000000000000000000000000000000000000002'], 'depth': 1, 'opName': 'PUSH3'}
{'pc': 35, 'op': 241, 'gas': '0x56017', 'gasCost': '0x3f67a', 'stack': ['0x40', '0x0', '0x40', '0x0', '0x2', '0x1000000000000000000000000000000000000002', '0x3d090'], 'depth': 1, 'opName': 'CALL'}
{'pc': 0, 'op': 96, 'gas': '0x3d98c', 'gasCost': '0x3', 'stack': [], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 2, 'op': 96, 'gas': '0x3d989', 'gasCost': '0x3', 'stack': ['0x1'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 4, 'op': 85, 'gas': '0x3d986', 'gasCost': '0x4e20', 'stack': ['0x1', '0x2'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 5, 'op': 51, 'gas': '0x38b66', 'gasCost': '0x2', 'stack': [], 'depth': 2, 'opName': 'CALLER'}
{'pc': 6, 'op': 96, 'gas': '0x38b64', 'gasCost': '0x3', 'stack': ['0x1000000000000000000000000000000000000001'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 8, 'op': 85, 'gas': '0x38b61', 'gasCost': '0x4e20', 'stack': ['0x1000000000000000000000000000000000000001', '0x4'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 9, 'op': 52, 'gas': '0x33d41', 'gasCost': '0x2', 'stack': [], 'depth': 2, 'opName': 'CALLVALUE'}
{'pc': 10, 'op': 96, 'gas': '0x33d3f', 'gasCost': '0x3', 'stack': ['0x2'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 12, 'op': 85, 'gas': '0x33d3c', 'gasCost': '0x4e20', 'stack': ['0x2', '0x7'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 13, 'op': 48, 'gas': '0x2ef1c', 'gasCost': '0x2', 'stack': [], 'depth': 2, 'opName': 'ADDRESS'}
{'pc': 14, 'op': 96, 'gas': '0x2ef1a', 'gasCost': '0x3', 'stack': ['0x1000000000000000000000000000000000000002'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 16, 'op': 85, 'gas': '0x2ef17', 'gasCost': '0x4e20', 'stack': ['0x1000000000000000000000000000000000000002', '0xe6'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 17, 'op': 50, 'gas': '0x2a0f7', 'gasCost': '0x2', 'stack': [], 'depth': 2, 'opName': 'ORIGIN'}
{'pc': 18, 'op': 96, 'gas': '0x2a0f5', 'gasCost': '0x3', 'stack': ['0xa94f5374fce5edbc8e2a8697c15331677e6ebf0b'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 20, 'op': 85, 'gas': '0x2a0f2', 'gasCost': '0x4e20', 'stack': ['0xa94f5374fce5edbc8e2a8697c15331677e6ebf0b', '0xe8'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 21, 'op': 54, 'gas': '0x252d2', 'gasCost': '0x2', 'stack': [], 'depth': 2, 'opName': 'CALLDATASIZE'}
{'pc': 22, 'op': 96, 'gas': '0x252d0', 'gasCost': '0x3', 'stack': ['0x40'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 24, 'op': 85, 'gas': '0x252cd', 'gasCost': '0x4e20', 'stack': ['0x40', '0xec'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 25, 'op': 56, 'gas': '0x204ad', 'gasCost': '0x2', 'stack': [], 'depth': 2, 'opName': 'CODESIZE'}
{'pc': 26, 'op': 96, 'gas': '0x204ab', 'gasCost': '0x3', 'stack': ['0x21'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 28, 'op': 85, 'gas': '0x204a8', 'gasCost': '0x4e20', 'stack': ['0x21', '0xee'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 29, 'op': 58, 'gas': '0x1b688', 'gasCost': '0x2', 'stack': [], 'depth': 2, 'opName': 'GASPRICE'}
{'pc': 30, 'op': 96, 'gas': '0x1b686', 'gasCost': '0x3', 'stack': ['0x1'], 'depth': 2, 'opName': 'PUSH1'}
{'pc': 32, 'op': 85, 'gas': '0x1b683', 'gasCost': '0x4e20', 'stack': ['0x1', '0xf0'], 'depth': 2, 'opName': 'SSTORE'}
{'pc': 36, 'op': 96, 'gas': '0x2d200', 'gasCost': '0x3', 'stack': ['0x1'], 'depth': 1, 'opName': 'PUSH1'}
{'pc': 38, 'op': 85, 'gas': '0x2d1fd', 'gasCost': '0x4e20', 'stack': ['0x1', '0x1'], 'depth': 1, 'opName': 'SSTORE'}
{'pc': 36, 'op': 96, 'gas': '0x2a7b66', 'gasCost': '0x3', 'stack': ['0x1'], 'depth': 0, 'opName': 'PUSH1'}
{'pc': 38, 'op': 85, 'gas': '0x2a7b63', 'gasCost': '0x4e20', 'stack': ['0x1', '0x0'], 'depth': 0, 'opName': 'SSTORE'}
{"output":"","gasUsed":"0x34775","time":1967173}

The text was updated successfully, but these errors were encountered:

debris · 2017-08-05T08:23:53Z

I like the idea of standarization very much! 👍

But if we are about to do that, there can't be any temporary workarounds. Can't a single operation result in two logs? One created before operation execution with the operation itself and the other one with result of the operation.

cdetrio · 2017-08-08T16:00:01Z

@debris this is to document a work-in-progress, so hopefully it will see incremental improvement.

If a single operation resulted in two logs, lots of information would be duplicated. I do like the idea of an error field, which would tell whether an operation failed due to an OOG or some other exception. But that would complicate the tracing logic quite a bit, and it would be non-trivial to implement in the clients I've worked with so far. Maybe if the failed operations are logged twice (the second with the failure) it would be easier for clients to implement?

cdetrio · 2017-08-08T16:01:04Z

VM trace data:

pc int64 (aka instruction counter) -- number of instructions executed so far in the current call.
opcode int64 -- the numeric id of the opcode to be executed.
depth int64 -- the current call depth, starting with 0.
gas int64 -- the current value of the gas counter. Descending.
opcode gas cost int64 -- the full cost of executing the current opcode (including memory costs).
result int256be -- the result put on stack after the execution of the opcode.
error code int64 -- the information about the failure of execution of the current opcode.
memory size int64 -- the current size of the memory.
pointer to memory void* -- the pointer to the memory.
opcode offset int64 -- the offset of the opcode in the code.

Notes:

(6) and (7) are hard to do, especially when the current opcode is CALL-like.
Knowing the gas cost (5) up front for CREATE is impossible. For calls we can assume max cost?
Instead of dumping the full stack, it is enough to show only the results of opcodes. The listener can reconstruct the full stack on its own.
Instead of the result (6) we can dump the top stack item. This would be relevant to the previous opcode.
In (9) we can allow the listener to read the parts of the memory it wants to (based on the memory size (8)). But this might be too intrusive and assumes memory is continuous. Maybe make this param optional?

axic · 2017-08-18T17:56:20Z

pc int64 (aka instruction counter)

I think it would make sense naming it differently since usually pc (program counter) refers to the byte offset.

gas int64 -- the current value of the gas counter. Descending.

Would name it gas left or gas remaining.

chfast · 2017-08-21T10:11:05Z

I think I confused pc. In C++ there are steps and pc being the current opcode index in the code. I agree PC is bad name, probably meaningful only for devs ever touching assembly.

axic · 2017-08-21T20:21:03Z

How about instead of the flat stack array:

stack: {
  removed: <count>
  inserted: [] // items inserted, first item is the top item on the stack
}

axic · 2017-08-21T20:25:34Z

Please specify how the values are represented:

which values are represented as numbers in JSON and which as strings
include zero padding in hexadecimals or truncate them (in this case: truncate to nibbles or not?)
include the 0x prefix in or not

cdetrio · 2017-09-21T20:29:55Z

Note that the "standardized trace" now also logs a stateRoot at the end of the trace. Here's an example from a cpp-ethereum trace for stZeroKnowledge/ecmul_0-3_9_21000_96:

{'depth': '0', 'gas': '21000', 'gasCost': '3', 'memory': [], 'op': 'PUSH1', 'pc': '0', 'stack': []}
{'depth': '0', 'gas': '20997', 'gasCost': '3', 'op': 'CALLDATALOAD', 'pc': '2', 'stack': ['0x00']}
{'depth': '0', 'gas': '20994', 'gasCost': '3', 'op': 'PUSH1', 'pc': '3', 'stack': ['0x30c8d1da00000000000000000000000000000000000000000000000000000000']}
{'depth': '0', 'gas': '20991', 'gasCost': '3', 'op': 'MSTORE', 'pc': '5', 'stack': ['0x30c8d1da00000000000000000000000000000000000000000000000000000000', '0x1c']}
{'depth': '0', 'gas': '20982', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000000000000000000000000000000000000000000000'], 'op': 'PUSH21', 'pc': '6', 'stack': []}
{'depth': '0', 'gas': '20979', 'gasCost': '3', 'op': 'PUSH1', 'pc': '28', 'stack': ['0x010000000000000000000000000000000000000000']}
{'depth': '0', 'gas': '20976', 'gasCost': '3', 'op': 'MSTORE', 'pc': '30', 'stack': ['0x010000000000000000000000000000000000000000', '0x20']}
{'depth': '0', 'gas': '20973', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000'], 'op': 'PUSH16', 'pc': '31', 'stack': []}
{'depth': '0', 'gas': '20970', 'gasCost': '3', 'op': 'PUSH1', 'pc': '48', 'stack': ['0xffffffffffffffffffffffffffffffff']}
{'depth': '0', 'gas': '20967', 'gasCost': '3', 'op': 'MSTORE', 'pc': '50', 'stack': ['0xffffffffffffffffffffffffffffffff', '0x40']}
{'depth': '0', 'gas': '20961', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff'], 'op': 'PUSH32', 'pc': '51', 'stack': []}
{'depth': '0', 'gas': '20958', 'gasCost': '3', 'op': 'PUSH1', 'pc': '84', 'stack': ['0xffffffffffffffffffffffffffffffff00000000000000000000000000000001']}
{'depth': '0', 'gas': '20955', 'gasCost': '3', 'op': 'MSTORE', 'pc': '86', 'stack': ['0xffffffffffffffffffffffffffffffff00000000000000000000000000000001', '0x60']}
{'depth': '0', 'gas': '20949', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff', 'ffffffffffffffffffffffffffffffff00000000000000000000000000000001'], 'op': 'PUSH21', 'pc': '87', 'stack': []}
{'depth': '0', 'gas': '20946', 'gasCost': '3', 'op': 'PUSH1', 'pc': '109', 'stack': ['0x02540be3fffffffffffffffffffffffffdabf41c00']}
{'depth': '0', 'gas': '20943', 'gasCost': '3', 'op': 'MSTORE', 'pc': '111', 'stack': ['0x02540be3fffffffffffffffffffffffffdabf41c00', '0x80']}
{'depth': '0', 'gas': '20937', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff', 'ffffffffffffffffffffffffffffffff00000000000000000000000000000001', '000000000000000000000002540be3fffffffffffffffffffffffffdabf41c00'], 'op': 'PUSH32', 'pc': '112', 'stack': []}
{'depth': '0', 'gas': '20934', 'gasCost': '3', 'op': 'PUSH1', 'pc': '145', 'stack': ['0xfffffffffffffffffffffffdabf41c00000000000000000000000002540be400']}
{'depth': '0', 'gas': '20931', 'gasCost': '3', 'op': 'MSTORE', 'pc': '147', 'stack': ['0xfffffffffffffffffffffffdabf41c00000000000000000000000002540be400', '0xa0']}
{'depth': '0', 'gas': '20925', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff', 'ffffffffffffffffffffffffffffffff00000000000000000000000000000001', '000000000000000000000002540be3fffffffffffffffffffffffffdabf41c00', 'fffffffffffffffffffffffdabf41c00000000000000000000000002540be400'], 'op': 'PUSH4', 'pc': '148', 'stack': []}
{'depth': '0', 'gas': '20922', 'gasCost': '3', 'op': 'PUSH1', 'pc': '153', 'stack': ['0x30c8d1da']}
{'depth': '0', 'gas': '20919', 'gasCost': '3', 'op': 'MLOAD', 'pc': '155', 'stack': ['0x30c8d1da', '0x00']}
{'depth': '0', 'gas': '20916', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff', 'ffffffffffffffffffffffffffffffff00000000000000000000000000000001', '000000000000000000000002540be3fffffffffffffffffffffffffdabf41c00', 'fffffffffffffffffffffffdabf41c00000000000000000000000002540be400'], 'op': 'EQ', 'pc': '156', 'stack': ['0x30c8d1da', '0x30c8d1da']}
{'depth': '0', 'gas': '20913', 'gasCost': '3', 'op': 'ISZERO', 'pc': '157', 'stack': ['0x01']}
{'depth': '0', 'gas': '20910', 'gasCost': '3', 'op': 'PUSH2', 'pc': '158', 'stack': ['0x00']}
{'depth': '0', 'gas': '20907', 'gasCost': '10', 'op': 'JUMPI', 'pc': '161', 'stack': ['0x00', '0x012b']}
{'depth': '0', 'gas': '20897', 'gasCost': '3', 'op': 'PUSH1', 'pc': '162', 'stack': []}
{'depth': '0', 'gas': '20894', 'gasCost': '3', 'op': 'PUSH1', 'pc': '164', 'stack': ['0xc0']}
{'depth': '0', 'gas': '20891', 'gasCost': '3', 'op': 'CALLDATALOAD', 'pc': '166', 'stack': ['0xc0', '0x04']}
{'depth': '0', 'gas': '20888', 'gasCost': '3', 'op': 'PUSH1', 'pc': '167', 'stack': ['0xc0', '0x20']}
{'depth': '0', 'gas': '20885', 'gasCost': '3', 'op': 'ADD', 'pc': '169', 'stack': ['0xc0', '0x20', '0x04']}
{'depth': '0', 'gas': '20882', 'gasCost': '3', 'op': 'CALLDATALOAD', 'pc': '170', 'stack': ['0xc0', '0x24']}
{'depth': '0', 'gas': '20879', 'gasCost': '3', 'op': 'GT', 'pc': '171', 'stack': ['0xc0', '0x60']}
{'depth': '0', 'gas': '20876', 'gasCost': '3', 'op': 'ISZERO', 'pc': '172', 'stack': ['0x00']}
{'depth': '0', 'gas': '20873', 'gasCost': '3', 'op': 'ISZERO', 'pc': '173', 'stack': ['0x01']}
{'depth': '0', 'gas': '20870', 'gasCost': '2', 'op': 'PC', 'pc': '174', 'stack': ['0x00']}
{'depth': '0', 'gas': '20868', 'gasCost': '10', 'op': 'JUMPI', 'pc': '175', 'stack': ['0x00', '0xae']}
{'depth': '0', 'gas': '20858', 'gasCost': '3', 'op': 'PUSH1', 'pc': '176', 'stack': []}
{'depth': '0', 'gas': '20855', 'gasCost': '3', 'op': 'CALLDATALOAD', 'pc': '178', 'stack': ['0x04']}
{'depth': '0', 'gas': '20852', 'gasCost': '3', 'op': 'PUSH1', 'pc': '179', 'stack': ['0x20']}
{'depth': '0', 'gas': '20849', 'gasCost': '3', 'op': 'ADD', 'pc': '181', 'stack': ['0x20', '0x04']}
{'depth': '0', 'gas': '20846', 'gasCost': '3', 'op': 'CALLDATALOAD', 'pc': '182', 'stack': ['0x24']}
{'depth': '0', 'gas': '20843', 'gasCost': '3', 'op': 'PUSH1', 'pc': '183', 'stack': ['0x60']}
{'depth': '0', 'gas': '20840', 'gasCost': '3', 'op': 'ADD', 'pc': '185', 'stack': ['0x60', '0x20']}
{'depth': '0', 'gas': '20837', 'gasCost': '3', 'op': 'PUSH1', 'pc': '186', 'stack': ['0x80']}
{'depth': '0', 'gas': '20834', 'gasCost': '3', 'op': 'CALLDATALOAD', 'pc': '188', 'stack': ['0x80', '0x04']}
{'depth': '0', 'gas': '20831', 'gasCost': '3', 'op': 'PUSH1', 'pc': '189', 'stack': ['0x80', '0x20']}
{'depth': '0', 'gas': '20828', 'gasCost': '3', 'op': 'ADD', 'pc': '191', 'stack': ['0x80', '0x20', '0x04']}
{'depth': '0', 'gas': '20825', 'gasCost': '3', 'op': 'PUSH2', 'pc': '192', 'stack': ['0x80', '0x24']}
{'depth': '0', 'gas': '20822', 'gasCost': '3', 'op': 'CALLDATACOPY', 'pc': '195', 'stack': ['0x80', '0x24', '0x0140']}
{'depth': '0', 'gas': '20783', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff', 'ffffffffffffffffffffffffffffffff00000000000000000000000000000001', '000000000000000000000002540be3fffffffffffffffffffffffffdabf41c00', 'fffffffffffffffffffffffdabf41c00000000000000000000000002540be400', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000060', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000003', '0000000000000000000000000000000000000000000000000000000000000009'], 'op': 'PUSH1', 'pc': '196', 'stack': []}
{'depth': '0', 'gas': '20780', 'gasCost': '3', 'op': 'PUSH2', 'pc': '198', 'stack': ['0x40']}
{'depth': '0', 'gas': '20777', 'gasCost': '3', 'op': 'PUSH2', 'pc': '201', 'stack': ['0x40', '0x0260']}
{'depth': '0', 'gas': '20774', 'gasCost': '3', 'op': 'MLOAD', 'pc': '204', 'stack': ['0x40', '0x0260', '0x0140']}
{'depth': '0', 'gas': '20771', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff', 'ffffffffffffffffffffffffffffffff00000000000000000000000000000001', '000000000000000000000002540be3fffffffffffffffffffffffffdabf41c00', 'fffffffffffffffffffffffdabf41c00000000000000000000000002540be400', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000060', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000003', '0000000000000000000000000000000000000000000000000000000000000009'], 'op': 'PUSH2', 'pc': '205', 'stack': ['0x40', '0x0260', '0x60']}
{'depth': '0', 'gas': '20768', 'gasCost': '3', 'op': 'PUSH1', 'pc': '208', 'stack': ['0x40', '0x0260', '0x60', '0x0160']}
{'depth': '0', 'gas': '20765', 'gasCost': '3', 'op': 'PUSH1', 'pc': '210', 'stack': ['0x40', '0x0260', '0x60', '0x0160', '0x00']}
{'depth': '0', 'gas': '20762', 'gasCost': '3', 'op': 'PUSH4', 'pc': '212', 'stack': ['0x40', '0x0260', '0x60', '0x0160', '0x00', '0x07']}
{'depth': '0', 'gas': '20759', 'gasCost': '0', 'op': 'CALL', 'pc': '217', 'stack': ['0x40', '0x0260', '0x60', '0x0160', '0x00', '0x07', '0x05f5e0ff']}
{'depth': '0', 'gas': '313', 'gasCost': '3', 'memory': ['0000000000000000000000000000000000000000000000000000000030c8d1da', '0000000000000000000000010000000000000000000000000000000000000000', '00000000000000000000000000000000ffffffffffffffffffffffffffffffff', 'ffffffffffffffffffffffffffffffff00000000000000000000000000000001', '000000000000000000000002540be3fffffffffffffffffffffffffdabf41c00', 'fffffffffffffffffffffffdabf41c00000000000000000000000002540be400', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000060', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000003', '0000000000000000000000000000000000000000000000000000000000000009', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000', '0000000000000000000000000000000000000000000000000000000000000000'], 'op': 'ISZERO', 'pc': '218', 'stack': ['0x00']}
{'depth': '0', 'gas': '310', 'gasCost': '2', 'op': 'PC', 'pc': '219', 'stack': ['0x01']}
{'depth': '0', 'gas': '308', 'gasCost': '10', 'op': 'JUMPI', 'pc': '220', 'stack': ['0x01', '0xdb']}
{'stateRoot': '618a348e7107ef322cd234fb11ab7c60f1cdb52278a0a29d1d14cb6788f55298'}

chfast · 2017-09-22T17:55:18Z

Because the the step report describes the EVM state before the opcode execution:

Can we report consumed stack items instead of full stack?
How do you want to report calls, in particular the CALL gas cost?

cdetrio · 2017-10-06T19:25:02Z

@chfast I think so, yes. instructions are logged before execution, whether the last step in the call depth (if the call OOGs), or the last step in the whole trace.

cdetrio · 2017-10-06T19:33:37Z

Can we report consumed stack items instead of full stack?

@chfast sure, feel free to prototype this.

How do you want to report calls, in particular the CALL gas cost?

I'm not sure its worth the trouble to log the gas cost of a step/instruction, since it can be calculated anyway from the difference in gas remaining between two steps. Currently for equivalence testing, we don't use the gas cost of a step that some clients include in the trace. We only use gas remaining.

chfast · 2017-10-08T13:08:55Z

@cdetrio, ok, but "gas remaining" should also be lowered by the cost of the just-to-be-executed instruction. So in case of an instruction resulting in OOG, the gas remaining must be negative. And in case of a call, we don't know the cost up front, so we only can take the "gas" argument of the call into consideration (C++ does it this way - a call cost it the basic CALL instruction cost + value transfer penalty + account creation penalty + the gas argument value).

cdetrio · 2017-10-08T23:06:05Z

Each step is logged with all values just before the execution, so the gas remaining should never be negative.

chfast · 2017-10-09T20:55:06Z

So in case an instruction is causing an exception, this step is not logged?

cdetrio · 2017-10-09T23:26:51Z

@chfast The only exception is invalid opcode steps, technically these could be logged too but currently they're filtered from the canonicalized trace (before doing the equivalence comparison check, for fuzz testing). This helps accommodate clients that don't log invalid opcodes, or that only log a generic exception but not the opcode itself. I can't remember which client (maybe pyeth).

All other steps (those with valid opcodes) are logged before execution. Also, the exceptions themselves are not explicitly logged (if a client does log exceptions, then its filtered when converting to the canonicalized trace). So where exceptions occur has to be deduced from the trace (e.g. by checking gas remaining where call depth decreases). Not labeling steps that cause exceptions is kind of annoying when reading a (canonicalized) trace, but for the purpose of equivalence fuzz testing its sufficient to just compare all steps without explicitly labeling where exceptions occur.

chfast · 2017-10-11T15:43:18Z

I think the term "just before execution" is a bit misleading. So in case of PUSH0 SLOAD with 100 units of gas the trace will be:

PUSH, gas remaining: 99

not

PUSH, gas remaining: 99
SLOAD, gas remaining: -101, status: OOG

cdetrio · 2017-10-11T19:18:44Z

@chfast the trace would be

PUSH, gas remaining: 100
SLOAD, gas remaining: 99

because on each step, its the gas remaining before execution and before gas deduction.

cdetrio · 2017-11-19T18:26:59Z

The json trace output from clients should be JSONL (JSON Lines).

pirapira · 2018-04-20T15:46:38Z

@winsvega perhaps retesteth should call debug_trace methods and check the format of the trace.

winsvega · 2018-04-20T18:56:57Z

you mean compare logs instead of root hashes?

pirapira · 2018-04-23T08:53:16Z

I suggested adding a new kind of test. I did not suggest replacing any existing tests that compare root hashes.

winsvega · 2018-04-23T11:51:07Z

the goal is actually to get rid of different test types and come to a general test format.

pirapira · 2018-04-23T11:53:23Z

@winsvega please use a separate GitHub issue for the most general test format.

chfast · 2018-05-11T10:35:12Z

@cdetrio @holiman I'm back to this issue because I want finally to implement this in EVMC.

I still believe it would be more convenient to report the effect of the instruction execution, not the state before the execution. In this case it might be enough to only report the top stack item being the result of the execution of the current opcode. Also the cost of the execution and exceptions can be reported.

qbzzt · 2021-03-01T03:22:14Z

It's in the EIP process: https://eips.ethereum.org/EIPS/eip-3155

winsvega · 2021-04-20T21:51:55Z

Devs and protocols are quite incompatible as we found out. Also being a top second cryptocurrency the teams can't afford or find the devs to work on concensus non critical issues. Everyone on their own. You want a vmtrace standard - you dig into everyones code and impliment it as your own fork. Fund an organization. Make public demonstrations, become a president to propose thise idea.

holgerd77 · 2021-04-21T09:15:25Z

@winsvega I've taken action and opened a new issue for that ethereumjs/ethereumjs-monorepo#1215 (so maybe no need to become president here, we'll see). 😛

winsvega · 2022-11-26T08:32:17Z

Currently geths evm trace is a standard.
Just run tests with --vmtraceraw on geth to see the format

cdetrio mentioned this issue Aug 4, 2017

Modify *trace* logging format to conform to spec ethereum/py-evm#62

Closed

cdetrio mentioned this issue Aug 8, 2017

standardized vmtrace logs ethereum/aleth#4320

Merged

cdetrio mentioned this issue Aug 9, 2017

standardized tracing ethereum/pyethereum#780

Merged

cdetrio mentioned this issue Aug 11, 2017

Metro-Byzantium Working Branch ethereumjs/ethereumjs-monorepo#161

Merged

jwasinger mentioned this issue Aug 11, 2017

Standardized VM Tracing ethereumjs/ethereumjs-monorepo#170

Closed

chfast mentioned this issue Aug 18, 2017

EVM-C: Support for VM tracing ethereum/evmjit#85

Closed

This was referenced Aug 24, 2017

[WIP] StateTest tracer using docker images for parity, cpp, geth ethereum/evmlab#6

Merged

core/vm, cmd/evm: standard vm traces ethereum/go-ethereum#15035

Merged

cdetrio mentioned this issue Sep 6, 2017

feature request: cmake flag to set EVM_OPTIMIZE=false ethereum/aleth#4475

Closed

jwasinger mentioned this issue Sep 7, 2017

add --jsontrace flag for state tests ethereumjs/ethereumjs-monorepo#194

Merged

winsvega assigned cdetrio Sep 13, 2017

winsvega added enhancement in progress up-for-grabs labels Sep 13, 2017

jwasinger mentioned this issue Oct 4, 2017

Print state root after transaction completion when --jsontrace is specified ethereumjs/ethereumjs-monorepo#212

Merged

cdetrio mentioned this issue Oct 6, 2017

standard trace fixes ethereum/aleth#4586

Merged

chfast mentioned this issue Oct 19, 2017

Improve aleth-vm tool interface ethereum/aleth#4613

Closed

cdetrio mentioned this issue Oct 20, 2017

print state root after json trace ethereum/aleth#4615

Merged

cdetrio mentioned this issue Dec 21, 2017

Std-json format for VM traces openethereum/parity-ethereum#7262

Merged

axic mentioned this issue Jan 23, 2018

Add evm tracing debug method ewasm/hera#114

Closed

jwasinger mentioned this issue Apr 27, 2018

trace before gas charge is applied ewasm/evm2wasm#233

Merged

MrChico mentioned this issue Oct 28, 2019

hevm: support json trace dapphub/dapptools#288

Closed

winsvega closed this as completed Nov 26, 2022

This was referenced Apr 12, 2023

nimbus t8n to support vmtrace status-im/nimbus-eth1#1544

Closed

evm t8n: Support evm trace ethereum/evmone#566

Closed

towards a standard EVM trace format #249

towards a standard EVM trace format #249

Comments

cdetrio commented Aug 4, 2017