Skip to content

chain/ethereum: Log reproducible call details on call failures - #6698

Open
tachyontec wants to merge 2 commits into
graphprotocol:masterfrom
tachyontec:tachyontec/json-rpc-logging
Open

chain/ethereum: Log reproducible call details on call failures #6698
tachyontec wants to merge 2 commits into
graphprotocol:masterfrom
tachyontec:tachyontec/json-rpc-logging

Conversation

@tachyontec

Copy link
Copy Markdown

Fixes #3404.

Problem

When a call handler fails to decode its trigger, the error tells you the function
ABI and nothing else:

failed to process trigger: block #21041413 (0x0000…b378), transaction a44fa185…:
Decoding function outputs for the call Function { name: "withdraw", inputs: [],
outputs: [Param { name: "", kind: Uint(256), internal_type: None }],
constant: None, state_mutability: NonPayable } failed, raw output: :
Invalid name: please ensure the contract and method you're calling exist!

There is no contract address and no calldata, so you cannot retry the call to see
what happened. raw output: has nothing after it, which looks like a broken
format string. What it actually means is that the call returned no data.

The address is already available where this error is raised. data_source.rs
builds a logging_extras block with the contract address and transaction hash in
the same EthereumTrigger::Call arm, but it builds it after both decode errors
have returned, so those errors never get it.

The eth_call path has the same problem for a different reason. decode() in
ethereum_adapter.rs threw away the request:

let call::Response { retval, source, req: _ } = resp;

req is the call::Request, and it holds the address and the encoded calldata.
Both failure branches then logged just a reason:

info!(logger, "Contract call reverted"; "reason" => "empty response");

There is already a log line with the right fields (fn, address, data,
block_hash, block_number), but it is on the success path and it is trace!,
so it is not there when a call fails in production.

Fix

chain/ethereum/src/data_source.rs: build one context string in the
EthereumTrigger::Call arm with the contract address, from, block number and
hash, transaction hash and calldata, and use it in both decode errors. That way
the field list is not written twice and the calldata is not printed twice. Hex is
0x-prefixed so you can paste it into an RPC request. Empty output now prints as
0x. A missing transaction_hash prints as none instead of None.

chain/ethereum/src/ethereum_adapter.rs: keep req and log its address and
calldata on both revert branches, along with fn, output, block_hash and
block_number. These are slog key/value fields and use the same names as the
existing eth_call trace. log_call_error gets the same fields. I also
0x-prefixed the existing trace so both lines look the same.

The second commit swaps the {:?} dump of the function for
Function::signature_with_outputs(). It is a separate commit so you can drop it
if you think it does not belong here.

Result

Before:

Decoding function outputs for the call Function { name: "withdraw", inputs: [],
outputs: [Param { name: "", kind: Uint(256), internal_type: None }],
constant: None, state_mutability: NonPayable } failed, raw output: : Invalid name: ...

After:

Decoding function outputs for the call withdraw()(uint256) failed,
contract: 0x5f4ec3df…, from: 0x1f98431c…, block: #21041413 (0x0000…b378),
transaction: 0xa44fa185…, raw input: 0x3ccfd60b, raw output: 0x : Invalid name: ...

It is shorter than before and you can rebuild the call from it.

Verification

The second commit changes the text of an error that can become a deterministic
subgraph failure, so I checked whether that text is used in Proof of Indexing. It
is not. ProofOfIndexingEvent::DeterministicError only holds
redacted_events: u64 and has no message field, and both StableHash impls hash
only that number (graph/src/components/subgraph/proof_of_indexing/event.rs). The
only place it is written is core/src/subgraph/trigger_processor.rs, which passes
a count from deterministic_errors.len() and never the error itself. So this does
not break consensus.

It does change the id of rows in the local subgraph_error table, because
insert_subgraph_error hashes the message into the primary key. That id is local
to one node and the insert uses on_conflict_do_nothing.

This only touches logging. No changes to control flow, error variants,
determinism classification (Deterministic vs PossibleReorg), or whether a call
counts as a revert.

Checks I ran: cargo fmt --all -- --check,
cargo clippy -p graph-chain-ethereum -- -D warnings (no warnings),
cargo test -p graph-chain-ethereum (59 passed), and
cargo check --workspace --all-targets.

One question

"Contract call reverted" is info!, and reverts are common rather than rare.
Subgraphs that probe symbol() or decimals() on odd tokens, or use try_ calls
that are meant to revert, will hit it a lot. This adds about 150 to 250 bytes per
line. I can drop block_hash, since you can get the block from block_number, or
move the calldata to debug! if that is too much.

Call handler decoding errors and eth_call reverts named the function
but nothing that identifies the call itself, so there was no way to
replay a failure. The address is already at hand in both places;
data_source.rs even builds a logging_extras block containing it, just
after the decode errors have returned.

Add the contract address, block, transaction hash, calldata and raw
output to these messages, 0x-prefixed so they can be pasted into an
RPC request. Empty return data now prints as 0x instead of nothing,
which used to look like a formatting bug.

Closes graphprotocol#3404
The call decoding errors printed the resolved function with {:?}, which
expands to the full alloy Function struct and dominates the message.
Use Function::signature_with_outputs() instead, rendering the same
information as `withdraw()(uint256)`.

This changes the text of a deterministic subgraph error. That text does
not participate in Proof of Indexing: the PoI event for a deterministic
error carries only a redacted-event count and has no message field, so
this is not consensus-breaking. It does change the derived id of rows
in the local subgraph_error table, which is a per-node dedup key only.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[Feature] Display the full JSON-RPC call in the logs that failed

1 participant