ibc: relayer can't find nodekey during packet proof query

[conorsch]

Describe the bug
The relayer currently fails to process withdrawals between Penumbra chains with the following error:

2023-07-13T21:58:00.807818Z     error   Error assembling packet message {"path_name": "penumbra_path", "chain_id": "penumbra-devnet-local-986947bb", "client_id": "07-tendermint-0", "msg": {"type": "timeout_packet", "src_port": "transfer", "src_channel": "channel-0", "dst_port": "transfer", "dst_channel": "channel-2", "sequence": 1, "timeout_height": "0-28824", "timeout_timestamp": 1689458273, "data": "CkFwYXNzZXQxOTg0ZmN0ZW53OG0yZnBsOGE5d3pndXpwN2ozNGQ3dnJhdnJ5dWhmdDgwOG55dDlmZGdncXhtYW5xbRIBMRqSAXBlbnVtYnJhdjJ0MXg0OGhkY2pxYTVqbGtneDJ3bmpzMHNnNjducWh3dHgwOGxreHVmNmo5YTh1cTk2MHlwbGNudnd1ZjJubm55NTM3OTJxZDg0bTIzY2o3azl0MjNlaDdlNmt3NTJsam4zcjNnZXZqbGttaGE5em54OXVxcXo3cWc0ZHQ4NmM5eTJuazA2bmh5IpIBcGVudW1icmF2MnQxa25lcWp4eDhndDJ0d2M4ODVnZm43bjJ0azY4bTczMDQzMmh4bHpuNDdocnptejI5YTR0aGNjejR5cWZrZnZqdm1qa3d4cHk0N2NscWhmNDVkOHpxOWo5ZWZ4ajk0YzJqeWhnem01OXNsZjhha3Bnd3cwNnh6ZWthNncyazA5ZnFhcWtncW4=", "ack": ""}, "error": "error querying packet proof: error querying tendermint proof for packet receipt: rpc error: code = Unknown desc = Missing node at NodeKey { version: 2338, nibble_path: 49c5 }."}

To Reproduce
Steps to reproduce the behavior:

1. Fire up a local devnet/preview connection, following docs in https://github.com/penumbra-zone/penumbra/tree/ed1cb0734aadb36059eb147c57b30694ff578002/deployments/relayer#running-a-local-devnet
2. Run the relayer via rly start
3. Attempt a withdrawal: pcli -n http://localhost:8080 tx withdraw penumbrav2t1kneqjxx8gt2twc885gfn7n2tk68m730432hxlzn47hrzmz29a4thccz4yqfkfvjvmjkwxpy47clqhf45d8zq9j9efxj94c2jyhgzm59slf8akpgww06xzeka6w2k09fqaqkgqn@penumbra-testnet-ganymede-be7bab59 upenumbra 1 channel-0

Note that you'll need to update the chain id in that address to be the actual chain id of testnet-preview. To find it: curl -s https://rpc.testnet-preview.penumbra.zone/status | jq -r .result.node_info.network.

Additional context
I made sure to update the to the latest penumbra protos in my local relayer build, and that did not resolve the problem. Let's dig around and figure out why the relayer is not happy looking up the packet proof.

[avahowell]

Can we run the relayer with Debug so we can see the output of this debug statement? (in PenumbraProvider.QueryTendermintProof)

cc.log.Debug("Querying K/V", zap.String("ChainId", cc.ChainId()), zap.Int64("Height", height), zap.String("Key", string(key))

[avahowell]

I think this error is returned by pd when we request a state key that doesn't exist

[avahowell]

this error is emitted by our jmt's TreeReader:

https://github.com/penumbra-zone/jmt/blob/3d374ed7de884d50cbcd9559ef0a53adaacbf828/src/reader.rs#L13

we're querying for a packet commitment that doesn't exist (this is possibly due to a channel id getting swapped, using the wrong channel id in the relayer due to an issue in our query or events api- note that the channels are different in your test, channel-0 vs channel-2)

[avahowell]

I found one issue: our state path for packet receipts is wrong:

penumbra/crates/core/component/ibc/src/component/state_key.rs

Line 78 in f5bfd68

"receipts/ports/{}/channels/{}/receipts/{}",

it should instead be

receipts/ports/{}/channels/{}/sequences/{}

[avahowell]

I think #2837 should fix this

[conorsch]

Testing this today, will report back with results.

[conorsch]

Unfortunately I'm still seeing the error, testing on the latest main, which includes #2837:

2023-07-14T18:51:02.267037Z     debug   Querying K/V    {"provider_type": "penumbra", "ChainId": "penumbra-testnet-ganymede-0b5ffff4", "Height": 1153, "Key": "receipts/ports/transfer/channels/channel-0/sequences/2"}
2023-07-14T18:51:02.312904Z     error   Error assembling packet message {"path_name": "penumbra_path", "chain_id": "penumbra-devnet-local-3a758144", "client_id": "07-tendermint-0", "msg": {"type": "timeout_packet", "src_port": "transfer", "src_channel": "channel-0", "dst_port": "transfer", "dst_channel": "channel-0", "sequence": 2, "timeout_height": "0-29165", "timeout_timestamp": 1689533450, "data": "CkFwYXNzZXQxOTg0ZmN0ZW53OG0yZnBsOGE5d3pndXpwN2ozNGQ3dnJhdnJ5dWhmdDgwOG55dDlmZGdncXhtYW5xbRIBMRqSAXBlbnVtYnJhdjJ0MXF0Y2ZlNjNzaHFjaHV1ajB6bHRydHhuamF5aHdkY2VrdmVhbTRzNXB3OHNzZHhyMDMyaGc4YXJua2VwNzl6NmpwNzh3dWw3dDN1MDJuZHhtZmsyeWMzdnF1OHduNmp3Y2R1NWt1Y3E0Y3dueTU0cGN6enluNTdha2d3NDlqMHMzMGtteXB0IpIBcGVudW1icmF2MnQxaGs0aHFsMG4zdWpsczU1ajBkd3Q4Y2w0a3NhdTc0eTBmMzlheWV3aGVsdXFjcG10bmEzamx4MGduZjIzemt6cjA5aGhyNXg3Z2x1eTJqdDgwMGRxMGo3Y3p1bGtyYWdwbmVjaHY3Yzh0czVoZDRjOXZsZDVhdW42cWFrN2p3bXByd256YWw=", "ack": ""}, "error": "error querying packet proof: error querying tendermint proof for packet receipt: rpc error: code = Unknown desc = Missing node at NodeKey { version: 1153, nibble_path: ba78 }."}

so a bit more investigation is required.

[conorsch]

This issue is resolved. In fact, it's so resolved that we have working IBC transfer between two Penumbra test chains:

$ pcli -n https://grpc.testnet-preview.penumbra.zone view balance
2023-07-20T21:33:36.601509Z  INFO penumbra_view::worker: starting client sync
Scanning blocks from last sync height 887 to latest height 888
[0s] ██████████████████████████████████████████████████       1/1       36/s ETA: 0s
 Account  Amount                        
 0        5transfer/channel-2/upenumbra

which is huge, and deserves its own writeup. I'm closing this issue as complete, but also cross-referencing related PRs that patched blocking bugs:

• ibc: start commitment_idx in packet commitment query at 1 to match ibc spec #2816
• fix ics20 withdrawal: include withdrawals in effect hash and tx builder #2820
• pd: add EventIndexLayer to enable tendermint event indexing #2828
• ibc: use ibc-types typed events, add SendPacket event #2829
• fix packet commitment paths: use sequences correctly #2837
• miscellaneous ICS20 fixes #2853