The last time I wrote about Ethereum logs was in 2018. This time we go deeper and try to recover a ghost event that devs have forgotten to add to the Yearn Vaults contract.

log Fees(management_fee, performance_fee, strategist_fee)

There are several methods to recover values from an internal view method or even add custom views to batch read private storage. One of the more interesting ones is a “state override” option of eth_call, which allows you to replace the code and storage for the context of the call.

To my deep disappointment, you can’t just set a breakpoint on a line you want, start a debugger to capture the local variables, and call it a day. This may change soon with a Vyper interpreter being in the works.

This post will describe a method based on capturing the values from a trace frame. The values we are interested in should appear on the stack or in the memory around this line.

The debug_traceTransaction method gives us trace frames with opcode-level resolution. To find the correct trace frame, we need to find the program counter around the end of _assessFees method execution. Maybe the metadata Vyper compiler generates could help us do that:

vyper -f source_map contracts/Vault.vy > source_map.json

The source map contains pc_jump_map and pc_pos_map, which looks promising. The jump map contains values of i, o, -, which seem to stand for jump in, jump out, and jump umm. Intuitively we want to find the jump out of the function, but it won’t be there since it’s the last internal method in the contract.

The position map is formatted as start_line, start_col, end_line, end_col for each program counter. This could help us limit the search window to the desired function. The simplest way to find the line numbers is to just look at the source file, but there are a dozen of Vault releases, and we want to automate the search as much as possible. Getting more metadata from the compiler wouldn’t hurt:

vyper -f ast contracts/Vault.vy > ast.json

This format outputs the abstract syntax tree of the parsed contract, which looks the same as Python ast. We can find all the definitions in the ast body, and find the function by name:

fn = next(item for item in ast["ast"]["body"] if item.get("name") == "_assessFees")

The definition would contain lineno and end_lineno, which is exactly what we need to scale the search to all versions. Now we can output all the program counters which have originated from a line range in the source and exist in the jump table.

They will also come in handy later when we need to deal with edge cases.

After writing a script that checks out all Vault releases from git tags and compiles them, we have enough metadata to start the search. But we still don’t have the concrete values to match on. Luckily it’s easy to convert Vyper to Python. You just rename the file.

Yearn Vaults also behave according to their apiVersion, so we can write a universal _assessFees function, which was an interesting enough exercise on its own. Even if it doesn’t handle all the edge cases yet, it works well enough to provide us with the calculated values to look for in a trace.

Tip: If you often work with Ethereum traces in Python, consider looking at evm-trace, it can parse both Geth- (opcode-level) and Parity-style (call-level) traces, turn them into a call tree, and display them to your liking via a custom display class.

A trace frame at the program counter we found contains all the values we need both on the stack and in memory, so I’ve hidden the memory part below and annotated the values I could identify on the stack.

{
    'pc': 21139,
    'op': 'JUMP',
    'gas': 1749825,
    'gasCost': 8,
    'depth': 7,
    'stack': [
        '0xa1d9bafc',
        '0x70a08231',
        '0x564bf2844654f149821697cc56572ee4384c05f7',
        '0x4b6f40465bd258c16',  # gain
        '0x339c',
        '0x127504',             # duration
        '0x4bd8d4001a87b5afe',  # management fee
        '0x78b2007092ea279b',   # strategist fee
        '0x78b2007092ea279b',   # performance fee
        '0x4b6f40465bd258c16',  # total fee
        '0x47bdec03915b3ac1b',
        '0x409154699c6bb4e1a',
        '0x93a62da5a14c80f265dabc077fcee437b1a0efde',
        '0xfd0877d9095789caf24c98f7cce092fa8e120775',
        '0x5294',
        '0x4204'
    ],
    'memory': [
        ...
    ]
}

But how exactly have we found it, you may ask? After helplessly trying to write a scanner, staring into an endless stream of results, and talking to a few people about this problem, I heard something very promising from @big_tech_sux:

The memory layout during the function execution is static.

This means we can patch the compiler and output the positions in memory for each memory variable just by adding one line:

print({sig.name: {name: varinfo.pos // 32 for varname, varinfo in context.vars.items()}})

This will output something like this, which allows us to add a named memory view of pc → name → value

{'_assessFees': {'#internal_0': 12, 'strategy': 10, 'gain': 11, 'duration': 13, 'management_fee': 14, 'strategist_fee': 15, 'performance_fee': 16, 'total_fee': 17}}

Wiring it all together, we can build a much better scanner, and also come up with a concise way of mapping the values from the named memory layout.

Even without the color coding marking the exact matches, you can clearly see the execution steps to grab the values from.

layout = MemoryLayout(trace, version)
data = layout[16164]
data["management_fee"] = layout[15686]["governance_fee"]
data["performance_fee"] = layout[15697]["governance_fee"] - data["management_fee"]
data["duration"] = extract_from_stack(trace, 15475, 2)

Old vaults work with the duration in place, so I repurposed the old scanner and matched multiple harvests on the literal value somewhere in the vicinity of the function.

We also need to filter out the program counters which repeat more than once, since such matches could make the result undefined.

After checking 13,000 harvests on mainnet, I’ve found a bunch of anomalies that my initial version couldn’t handle, namely, multiple harvests in the same transaction, and fee adjustments sandwiching the harvests, likely related to accounting fixes.

If we read the state from a previous block, we’ll get an incorrect result from the calculation method, the duration for the second harvest in the same block would be zero, so no management fees would be applied. Luckily we can tell the order of events using log_index and only set the duration for the first harvest of the same vault (for <0.3.5) or the same strategy (<0.4.0). Since 0.4.0 harvesting the same strategy in the same block is not allowed.

Another problem is getting the fee configuration if it was changed in the middle of the transaction. I came up with a tiny extension for dict which returns the closest previous value. Then I stored all the fee changes using (block_number, log_index) as an index.

class AsofDict(dict):
    def __getitem__(self, key):
        return super().__getitem__(last(item for item in sorted(self) if item <= key))

The third problem is the trace with multiple harvests is completely wrong, it has the same program counters repeating and it doesn’t say which contract we are currently in. You can either parse it into a call tree with evm-trace, or simply split on the JUMPDEST into a function and JUMP out of it, which is what I did.

The 0.4.x series of vaults has demanded a more complex splitting logic since the function could exit early when there was no gain and the only value we could recover is duration.

In the end, this didn’t work well either, and I changed the JUMP for a LOG2 where the StrategyReported event is fired. Since our frames have memory and stack parsed as integers, we need to convert the topic to int.

decode_single('uint256', keccak(text=vault.StrategyReported.abi.selector))

In the process I discovered a quirk with Vyper 0.2.8 which affects three of the oldest releases, it has the first and the last value in the pc_pos_map swapped. I fixed this by hand.

Having two distinct implementations has helped immensely to make both of them more robust. I was mostly using the calculation implementation as a reference one, but in this example the traces method was correct. It turned out vaults before 0.3.5 have tracked lastReport at the vault level, not at per strategy level as newer vaults do.

Note: some of what you see here is an aspirational api. If you want to repeat something, you may need some bunny patches for ape.

Yearn Registry makes it trivial to find all Vault deployments and their corresponding versions:

$ ape console --network :mainnet:geth
registry = Contract('v2.registry.ychad.eth')
vaults = groupby(attrgetter('api_version'), registry.NewVault)

Similarly, it’s easy to find all the harvests:

vault = Contract(address)
reports = list(vault.StrategyReported)

We can find some more complex transactions to crush the remaining bugs using the new memory-viewing and frame-searching tools at our disposal:

def txs_with_multiple_strategy_harvests():
    reports = get_reports()
    return valfilter(
        lambda logs: len(logs) >= 2,
        groupby(lambda log: (log.transaction_hash, log.strategy), reports),
    )

Now we can parallelize with it and write the results in Postgres using pony, which is a nice Pythonic database library. For each report, we run both methods before writing to db and fail if the results don’t match perfectly, saving edge cases for further analysis.

With traces being so giant (I’ve seen a 4GB one), we also need a caching system. Luckily traces compress really well, 50-100x even with gzip, so we modify diskcache to use it and not use pickletools.optimize, which is incredibly slow for large objects.

If you port your pipeline to dask, you can run it in multiple worker processes, each running a thread pool, and even scale to multiple machines. It’s easy, since dask mostly consists of drop-in replacement for things you already know and love like pandas, numpy, and concurrent.futures. It would also automatically distribute the load and restart the crashed or memory-leaking workers for you.

If you need another reason to try dask, it comes with an amazing dashboard, which shows resource usage and even a flamegraph of the execution profile, which is super handy when optimizing for speed. Let’s take a look at it.

You can clearly see that loading the data takes even more time than the request itself. The culprit is probably the attrdict middleware that converts dict responses and adds attribute access to them. This seems like a poor idea when dealing with traces, which can have hundreds of thousands of elements.

%time web3.manager.request_blocking('debug_traceTransaction', tx)
Wall time: 33 s

web3.middleware_onion.remove('attrdict')

%time web3.manager.request_blocking('debug_traceTransaction', tx)
Wall time: 8.5 s

Hopefully, traces will become faster when Erigon adds transaction-level state index. Currently it has to execute all previous transaction in the block, and most of this work goes to waste.

I rewrote how we fetch and parse the traces and the performance has improved significantly. Now I can just sit back and finish up this article while the indexing is still going.

Shortly after publishing the article I dared MEV big brains to tell me there is a better method and one person has actually suggested it:

The way I implemented it is you have a source folder, where you can change or add any functionality to contracts. Then you fork at a previous block using anvil, disable auto-mining, recompile if there were any source changes, replace the code, and replay all the preceding transactions (you don’t need to do anything with impersonated accounts, just replay as is with the original signatures).

Then you fetch a receipt and find your newly added logs there. This method is slow, on the order of minutes, but it has helped to resolve the stalemate between two other methods, which was related to Strategy.delegatedAssets which has changed mid-block and has lead to a slight error in the assess method.

All the code related to this article can be found in this repo.

Special thanks to @big_tech_sux, @flashfish0x, @wavey0x.

The last time I wrote about Ethereum logs was in 2018. This time we go deeper and try to recover a ghost event that devs have forgotten to add to the Yearn Vaults contract.

log Fees(management_fee, performance_fee, strategist_fee)

There are several methods to recover values from an internal view method or even add custom views to batch read private storage. One of the more interesting ones is a “state override” option of eth_call, which allows you to replace the code and storage for the context of the call.

To my deep disappointment, you can’t just set a breakpoint on a line you want, start a debugger to capture the local variables, and call it a day. This may change soon with a Vyper interpreter being in the works.

This post will describe a method based on capturing the values from a trace frame. The values we are interested in should appear on the stack or in the memory around this line.

The debug_traceTransaction method gives us trace frames with opcode-level resolution. To find the correct trace frame, we need to find the program counter around the end of _assessFees method execution. Maybe the metadata Vyper compiler generates could help us do that:

vyper -f source_map contracts/Vault.vy > source_map.json

The source map contains pc_jump_map and pc_pos_map, which looks promising. The jump map contains values of i, o, -, which seem to stand for jump in, jump out, and jump umm. Intuitively we want to find the jump out of the function, but it won’t be there since it’s the last internal method in the contract.

The position map is formatted as start_line, start_col, end_line, end_col for each program counter. This could help us limit the search window to the desired function. The simplest way to find the line numbers is to just look at the source file, but there are a dozen of Vault releases, and we want to automate the search as much as possible. Getting more metadata from the compiler wouldn’t hurt:

vyper -f ast contracts/Vault.vy > ast.json

This format outputs the abstract syntax tree of the parsed contract, which looks the same as Python ast. We can find all the definitions in the ast body, and find the function by name:

fn = next(item for item in ast["ast"]["body"] if item.get("name") == "_assessFees")

The definition would contain lineno and end_lineno, which is exactly what we need to scale the search to all versions. Now we can output all the program counters which have originated from a line range in the source and exist in the jump table.

They will also come in handy later when we need to deal with edge cases.

After writing a script that checks out all Vault releases from git tags and compiles them, we have enough metadata to start the search. But we still don’t have the concrete values to match on. Luckily it’s easy to convert Vyper to Python. You just rename the file.

Yearn Vaults also behave according to their apiVersion, so we can write a universal _assessFees function, which was an interesting enough exercise on its own. Even if it doesn’t handle all the edge cases yet, it works well enough to provide us with the calculated values to look for in a trace.

Tip: If you often work with Ethereum traces in Python, consider looking at evm-trace, it can parse both Geth- (opcode-level) and Parity-style (call-level) traces, turn them into a call tree, and display them to your liking via a custom display class.

A trace frame at the program counter we found contains all the values we need both on the stack and in memory, so I’ve hidden the memory part below and annotated the values I could identify on the stack.

{
    'pc': 21139,
    'op': 'JUMP',
    'gas': 1749825,
    'gasCost': 8,
    'depth': 7,
    'stack': [
        '0xa1d9bafc',
        '0x70a08231',
        '0x564bf2844654f149821697cc56572ee4384c05f7',
        '0x4b6f40465bd258c16',  # gain
        '0x339c',
        '0x127504',             # duration
        '0x4bd8d4001a87b5afe',  # management fee
        '0x78b2007092ea279b',   # strategist fee
        '0x78b2007092ea279b',   # performance fee
        '0x4b6f40465bd258c16',  # total fee
        '0x47bdec03915b3ac1b',
        '0x409154699c6bb4e1a',
        '0x93a62da5a14c80f265dabc077fcee437b1a0efde',
        '0xfd0877d9095789caf24c98f7cce092fa8e120775',
        '0x5294',
        '0x4204'
    ],
    'memory': [
        ...
    ]
}

But how exactly have we found it, you may ask? After helplessly trying to write a scanner, staring into an endless stream of results, and talking to a few people about this problem, I heard something very promising from @big_tech_sux:

The memory layout during the function execution is static.

This means we can patch the compiler and output the positions in memory for each memory variable just by adding one line:

print({sig.name: {name: varinfo.pos // 32 for varname, varinfo in context.vars.items()}})

This will output something like this, which allows us to add a named memory view of pc → name → value

{'_assessFees': {'#internal_0': 12, 'strategy': 10, 'gain': 11, 'duration': 13, 'management_fee': 14, 'strategist_fee': 15, 'performance_fee': 16, 'total_fee': 17}}

Wiring it all together, we can build a much better scanner, and also come up with a concise way of mapping the values from the named memory layout.

Even without the color coding marking the exact matches, you can clearly see the execution steps to grab the values from.

layout = MemoryLayout(trace, version)
data = layout[16164]
data["management_fee"] = layout[15686]["governance_fee"]
data["performance_fee"] = layout[15697]["governance_fee"] - data["management_fee"]
data["duration"] = extract_from_stack(trace, 15475, 2)

Old vaults work with the duration in place, so I repurposed the old scanner and matched multiple harvests on the literal value somewhere in the vicinity of the function.

We also need to filter out the program counters which repeat more than once, since such matches could make the result undefined.

After checking 13,000 harvests on mainnet, I’ve found a bunch of anomalies that my initial version couldn’t handle, namely, multiple harvests in the same transaction, and fee adjustments sandwiching the harvests, likely related to accounting fixes.

If we read the state from a previous block, we’ll get an incorrect result from the calculation method, the duration for the second harvest in the same block would be zero, so no management fees would be applied. Luckily we can tell the order of events using log_index and only set the duration for the first harvest of the same vault (for <0.3.5) or the same strategy (<0.4.0). Since 0.4.0 harvesting the same strategy in the same block is not allowed.

Another problem is getting the fee configuration if it was changed in the middle of the transaction. I came up with a tiny extension for dict which returns the closest previous value. Then I stored all the fee changes using (block_number, log_index) as an index.

class AsofDict(dict):
    def __getitem__(self, key):
        return super().__getitem__(last(item for item in sorted(self) if item <= key))

The third problem is the trace with multiple harvests is completely wrong, it has the same program counters repeating and it doesn’t say which contract we are currently in. You can either parse it into a call tree with evm-trace, or simply split on the JUMPDEST into a function and JUMP out of it, which is what I did.

The 0.4.x series of vaults has demanded a more complex splitting logic since the function could exit early when there was no gain and the only value we could recover is duration.

In the end, this didn’t work well either, and I changed the JUMP for a LOG2 where the StrategyReported event is fired. Since our frames have memory and stack parsed as integers, we need to convert the topic to int.

decode_single('uint256', keccak(text=vault.StrategyReported.abi.selector))

In the process I discovered a quirk with Vyper 0.2.8 which affects three of the oldest releases, it has the first and the last value in the pc_pos_map swapped. I fixed this by hand.

Having two distinct implementations has helped immensely to make both of them more robust. I was mostly using the calculation implementation as a reference one, but in this example the traces method was correct. It turned out vaults before 0.3.5 have tracked lastReport at the vault level, not at per strategy level as newer vaults do.

Note: some of what you see here is an aspirational api. If you want to repeat something, you may need some bunny patches for ape.

Yearn Registry makes it trivial to find all Vault deployments and their corresponding versions:

$ ape console --network :mainnet:geth
registry = Contract('v2.registry.ychad.eth')
vaults = groupby(attrgetter('api_version'), registry.NewVault)

Similarly, it’s easy to find all the harvests:

vault = Contract(address)
reports = list(vault.StrategyReported)

We can find some more complex transactions to crush the remaining bugs using the new memory-viewing and frame-searching tools at our disposal:

def txs_with_multiple_strategy_harvests():
    reports = get_reports()
    return valfilter(
        lambda logs: len(logs) >= 2,
        groupby(lambda log: (log.transaction_hash, log.strategy), reports),
    )

Now we can parallelize with it and write the results in Postgres using pony, which is a nice Pythonic database library. For each report, we run both methods before writing to db and fail if the results don’t match perfectly, saving edge cases for further analysis.

With traces being so giant (I’ve seen a 4GB one), we also need a caching system. Luckily traces compress really well, 50-100x even with gzip, so we modify diskcache to use it and not use pickletools.optimize, which is incredibly slow for large objects.

If you port your pipeline to dask, you can run it in multiple worker processes, each running a thread pool, and even scale to multiple machines. It’s easy, since dask mostly consists of drop-in replacement for things you already know and love like pandas, numpy, and concurrent.futures. It would also automatically distribute the load and restart the crashed or memory-leaking workers for you.

If you need another reason to try dask, it comes with an amazing dashboard, which shows resource usage and even a flamegraph of the execution profile, which is super handy when optimizing for speed. Let’s take a look at it.

You can clearly see that loading the data takes even more time than the request itself. The culprit is probably the attrdict middleware that converts dict responses and adds attribute access to them. This seems like a poor idea when dealing with traces, which can have hundreds of thousands of elements.

%time web3.manager.request_blocking('debug_traceTransaction', tx)
Wall time: 33 s

web3.middleware_onion.remove('attrdict')

%time web3.manager.request_blocking('debug_traceTransaction', tx)
Wall time: 8.5 s

Hopefully, traces will become faster when Erigon adds transaction-level state index. Currently it has to execute all previous transaction in the block, and most of this work goes to waste.

I rewrote how we fetch and parse the traces and the performance has improved significantly. Now I can just sit back and finish up this article while the indexing is still going.

Shortly after publishing the article I dared MEV big brains to tell me there is a better method and one person has actually suggested it:

The way I implemented it is you have a source folder, where you can change or add any functionality to contracts. Then you fork at a previous block using anvil, disable auto-mining, recompile if there were any source changes, replace the code, and replay all the preceding transactions (you don’t need to do anything with impersonated accounts, just replay as is with the original signatures).

Then you fetch a receipt and find your newly added logs there. This method is slow, on the order of minutes, but it has helped to resolve the stalemate between two other methods, which was related to Strategy.delegatedAssets which has changed mid-block and has lead to a slight error in the assess method.

All the code related to this article can be found in this repo.

Special thanks to @big_tech_sux, @flashfish0x, @wavey0x.