Modify *trace* logging format to conform to spec

[pipermerriam]

What is wrong?

There is a spec of some form which the data generated by tracing a transaction execution generates. Py-EVM needs to conform to that.

How can it be fixed

Talk with @cdetrio and figure out where this format is documented if anywhere and then make the appropriate changes.

[cdetrio]

Here's some notes on a standard trace format: ethereum/tests#249

[rayrapetyan]

@pipermerriam, @cdetrio could you guide here - is there something else beyond extending current logging message in "apply_computation" function?

[pipermerriam]

@rayrapetyan the logging.trace statements and this are only loosely related. Currently, all of the TRACE and logging.trace level logging is simply normal python logging.

This issue is about the ability to generate debug information about EVM execution. See https://github.com/ethereum/go-ethereum/wiki/Management-APIs#debug_traceblock for the format that go-ethereum uses.

I had originally hoped that we could facilitate this via the python standard library logging APIs. The idea was use something like this API on the logging.Filter class to impart the contextual information about the EVM execution state (stack, memory, gas, etc). Then we could use a special logging.Handler to extract the relevant logging statements and extract the data that way.

I'm not set on this implementation plan, just on having some way to get EVM trace data from transaction and block execution.

[rayrapetyan]

@pipermerriam, so this issue is about implementing non-standard debug_* APIs and exposing them via JSON-RPC, correct? If yes - is rpc/modules/debug.py a good place to start coding from? Or a more generic rpc/modules/manage.py is better? Would be great if you can describe high-level interfaces we need here.

[pipermerriam]

I think this needs to be implemented in the eth module and and then exposed via something like rpc/modules/debug.py.

[rayrapetyan]

In go implementation, debug_traceBlock is based on debug_traceTransaction calls, which supports pretty advanced options, e.g. optional JavaScript-based transaction tracing. Do we need to support this as well?

[pipermerriam]

@rayrapetyan no, for now I think it's adequate to start with just the full trace data as documented in the debug_traceTransaction endpoint. Things like disabling stack/storage/etc are probably features we can push to a subsequent PR.

[rayrapetyan]

@pipermerriam, so I'm trying to obtain a state/computation of a chain right before a transaction with hash tx_hash, for that I use:

    (tx_block_num, tx_ix) = chain.chaindb.get_transaction_index(decode_hex(tx_hash))
    tx_block = chain.get_canonical_block_by_number(tx_block_num)
    parent_block = chain.get_canonical_block_by_number(tx_block_num - 1)

    base_header = chain.ensure_header(parent_block.header)
    vm = chain.get_vm(base_header)

    if tx_ix > 0:
        _, _, comps = vm.apply_all_transactions(transactions=tx_block.transactions[0:tx_ix-1], base_header=base_header)

However it fails in state.py at:

if self.state_root != BLANK_ROOT_HASH and not self.account_db.has_root(self.state_root):
            raise StateRootNotFound(self.state_root)

Any idea of how to obtain a valid pre-execution state/computation for transaction with a given hash?

[pipermerriam]

It'd be good to have a full-ish stacktrace to diagnose why you're seeing this error

[rayrapetyan]

@pipermerriam,

File "/ara/devel/blockchain/py-evm/eth/utils/trace.py", line 58, in trace_transaction
    _, _, comps = vm.apply_all_transactions(transactions=tx_block.transactions[1:tx_ix], base_header=base_header)
  File "/ara/devel/blockchain/py-evm/eth/vm/base.py", line 493, in apply_all_transactions
    transaction,
  File "/ara/devel/blockchain/py-evm/eth/vm/base.py", line 409, in apply_transaction
    state_root, computation = self.state.apply_transaction(transaction)
  File "/ara/devel/blockchain/py-evm/eth/vm/state.py", line 250, in apply_transaction
    raise StateRootNotFound(self.state_root)
eth.exceptions.StateRootNotFound: b'U\xb7@6!\xb3\x90/\x15\xa2\x03r\xa4w\xc1\xe3\xe2Q\xd9@lu\x88\xcd\x88w\xcd\xc9I\xbe\xa4^'

So I'm basically trying to apply transactions from block N to VM obtained from block N-1.
I can't figure out meaning of:
"and not self.account_db.has_root(self.state_root)"
How could it be that self.account_db of a valid VM (we obtained from block N-1) may not contain self.state_root?

[pipermerriam]

@rayrapetyan we garbage collect the state trie so it's likely that the state root for block N-1 is no longer present in the database. We currently don't have any public APIs for disabling this behavior.

[rayrapetyan]

@pipermerriam, could you point me to the code which clears state trie in a full-chain node? We have to have state available in order to trace execution of any transaction from any block I believe...

[carver]

we garbage collect the state trie

If this started happening, I missed it. AFAIK, we archive all the old states that we process during regular sync. But...

If we skipped over a block during fast sync, then we most likely don't have the state at that block's state root.

Are you running this against a live network? You should be able to create a local in-memory chain with some custom transactions to test with, then the state will definitely be present.

Otherwise, be sure to test against a block that was synced during regular sync.

[rayrapetyan]

@carver, I've created a new Ropsten full node from scratch and synced first few thousands of blocks from the network. Then trying to apply transactions from block 11 on top of block 10 and getting this stateRoot error, seems like state tree is not there in account_db.

[carver]

I've created a new Ropsten full node from scratch and synced first few thousands of blocks from the network.

Ah, you did a partial fast sync so there won't be any state data yet. Fast sync just pulls headers and blocks, but doesn't actually process any of them. Then when it catches up, it requests all the state data from peers.

You could force a regular sync right away in code. There is no cmd line option to do it yet. One way to do it would be to start from a fresh db, and deleting all these lines:

py-evm/trinity/sync/full/service.py

Lines 39 to 76 in 2a6f3cb

	head = await self.wait(self.chaindb.coro_get_canonical_head())
	# We're still too slow at block processing, so if our local head is older than
	# FAST_SYNC_CUTOFF we first do a fast-sync run to catch up with the rest of the network.
	# See https://github.com/ethereum/py-evm/issues/654 for more details
	if head.timestamp < time.time() - FAST_SYNC_CUTOFF:
	# Fast-sync chain data.
	self.logger.info("Starting fast-sync; current head: %s", head)
	fast_syncer = FastChainSyncer(
	self.chain,
	self.chaindb,
	self.peer_pool,
	self.cancel_token,
	)
	await fast_syncer.run()
	previous_head = head
	head = await self.wait(self.chaindb.coro_get_canonical_head())
	self.logger.info(
	"Finished fast fast-sync; previous head: %s, current head: %s", previous_head, head
	)
	# remove the reference so the memory can be reclaimed
	del fast_syncer
	if self.cancel_token.triggered:
	return
	# Ensure we have the state for our current head.
	if head.state_root != BLANK_ROOT_HASH and head.state_root not in self.base_db:
	self.logger.info(
	"Missing state for current head %s, downloading it", head)
	downloader = StateDownloader(
	self.chaindb, self.base_db, head.state_root, self.peer_pool, self.cancel_token)
	await downloader.run()
	# remove the reference so the memory can be reclaimed
	del downloader
	if self.cancel_token.triggered:
	return

Looks like that should skip straight to regular sync, though I haven't tried it.

[rayrapetyan]

Thanks @carver, will try that.

[rayrapetyan]

@carver, @pipermerriam, thanks, it worked. I'm more or less done with everything, except some high-level design approach. See, In py-evm computation is performed in a context of:

with cls(state, message, transaction_context) as computation:
     ....(we need to trace code here)

Now, we can pass tracer flag\options as a new param all the way down to this point: (VM -> State -> TransactionExecutor -> Computator) or store it somewhere else (e.g. in a "state" or "message" params passed to apply_computation function).

I don't really like any of these approaches. What are your thoughts here? Thanks.

[carver]

Can you open a WIP PR? It's much easier to discuss details in the context of a PR. (You can just add comments on lines that have open questions).

[cburgdorf]

@rayrapetyan just letting you know that I will create a bounty for this issue and have you assigned. Thanks for pushing this further!

[gitcoinbot]

Issue Status: 1. Open 2. Started 3. Submitted 4. Done

---

This issue now has a funding of 120.0 DAI (120.0 USD @ $1.0/DAI) attached to it as part of the Ethereum Foundation fund.

• If you would like to work on this issue you can 'start work' on the Gitcoin Issue Details page.
• Want to chip in? Add your own contribution here.
• Questions? Checkout Gitcoin Help or the Gitcoin Slack
• $34,761.81 more funded OSS Work available on the Gitcoin Issue Explorer

[gitcoinbot]

Issue Status: 1. Open 2. Started 3. Submitted 4. Done

---

Work has been started.

These users each claimed they can complete the work by 8 months, 3 weeks from now.
Please review their action plans below:

1) zyfrank has applied to start work (Funders only: approve worker | reject worker).

Seems a good task for beginner, I'd like to take it as my first step to the explore of Py-EVM

Learn more on the Gitcoin Issue Details page.

2) rayrapetyan has been approved to start work.

Will complete #1515 (#62) on top of #1531.

Learn more on the Gitcoin Issue Details page.

[pipermerriam]

@rayrapetyan currently has first right of refusal for this since he started work on it already.

[gitcoinbot]

@rayrapetyan Hello from Gitcoin Core - are you still working on this issue? Please submit a WIP PR or comment back within the next 3 days or you will be removed from this ticket and it will be returned to an ‘Open’ status. Please let us know if you have questions!

• reminder (3 days)
• escalation to mods (6 days)

Funders only: Snooze warnings for 1 day | 3 days | 5 days | 10 days | 100 days

[rayrapetyan]

WIP PR: #1515

[gitcoinbot]

@rayrapetyan Hello from Gitcoin Core - are you still working on this issue? Please submit a WIP PR or comment back within the next 3 days or you will be removed from this ticket and it will be returned to an ‘Open’ status. Please let us know if you have questions!

• reminder (3 days)
• escalation to mods (6 days)

Funders only: Snooze warnings for 1 day | 3 days | 5 days | 10 days | 100 days

[gitcoinbot]

@rayrapetyan Hello from Gitcoin Core - are you still working on this issue? Please submit a WIP PR or comment back within the next 3 days or you will be removed from this ticket and it will be returned to an ‘Open’ status. Please let us know if you have questions!

• reminder (3 days)
• escalation to mods (6 days)

Funders only: Snooze warnings for 1 day | 3 days | 5 days | 10 days | 100 days

[pipermerriam]

@gitcoinbot this issue can be considered done and the bounty paid to @rayrapetyan

[gitcoinbot]

Issue Status: 1. Open 2. Started 3. Submitted 4. Done

---

Work for 120.0 DAI (120.0 USD @ $1.0/DAI) has been submitted by:

1. @rayrapetyan

@ceresstation please take a look at the submitted work:

• PR by @rayrapetyan

---

• Learn more on the Gitcoin Issue Details page
• Want to chip in? Add your own contribution here.
• Questions? Checkout Gitcoin Help or the Gitcoin Slack
• $44,467.55 more funded OSS Work available on the Gitcoin Issue Explorer

[gitcoinbot]

⚡️ A *Pythonista* Kudos has been sent to @rayrapetyan for this issue from @ceresstation. ⚡️ Nice work @rayrapetyan! Your Kudos has automatically been sent in the ETH address we have on file.

[gitcoinbot]

Issue Status: 1. Open 2. Started 3. Submitted 4. Done

---

The funding of 120.0 DAI (120.0 USD @ $1.0/DAI) attached to this issue has been approved & issued to @rayrapetyan.

• Learn more on the Gitcoin Issue Details page
• Questions? Checkout Gitcoin Help or the Gitcoin Slack
• $45,380.67 more funded OSS Work available on the Gitcoin Issue Explorer