Hermes may send timeouts for packets that have not expired yet

[ancazamfir]

Crate

relayer

Summary of Bug

hermes checks now() when deciding if a packet has timedout. This causes timeouts to be rejected by chain if the timestamp of the header for the consensus state on the counterparty chain is smaller than now()

error looks like this:

{
  "jsonrpc": "2.0",
  "id": -1,
  "result": {
    "hash": "7198EAB9E735D2990B8D844C530B02F94D2090951FA2413C9FF760D2F1C72051",
    "height": "212",
    "index": 1,
    "tx_result": {
      "code": 14,
      "data": null,
      "log": "\ngithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk/x/ibc/core/04-channel/keeper.Keeper.TimeoutPacket\n\tgithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk@v0.42.10/x/ibc/core/04-channel/keeper/timeout.go:78\ngithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk/x/ibc/core/keeper.Keeper.Timeout\n\tgithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk@v0.42.10/x/ibc/core/keeper/msg_server.go:493\ngithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk/x/ibc/core.NewHandler.func1\n\tgithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk@v0.42.10/x/ibc/core/handler.go:87\ngithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk/baseapp.(*BaseApp).runMsgs\n\tgithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk@v0.42.10/baseapp/baseapp.go:724\ngithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk/baseapp.(*BaseApp).runTx\n\tgithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk@v0.42.10/baseapp/baseapp.go:669\ngithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk/baseapp.(*BaseApp).DeliverTx\n\tgithub.yoyoweb123.workers.dev/cosmos/cosmos-sdk@v0.42.10/baseapp/abci.go:273\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/abci/client.(*localClient).DeliverTxAsync\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/abci/client/local_client.go:95\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/proxy.(*appConnConsensus).DeliverTxAsync\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/proxy/app_conn.go:85\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/state.execBlockOnProxyApp\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/state/execution.go:320\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/state/execution.go:140\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).finalizeCommit\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:1635\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).tryFinalizeCommit\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:1546\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).enterCommit.func1\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:1481\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).enterCommit\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:1519\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).addVote\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:2132\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).tryAddVote\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:1930\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).handleMsg\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:838\ngithub.yoyoweb123.workers.dev/tendermint/tendermint/consensus.(*State).receiveRoutine\n\tgithub.yoyoweb123.workers.dev/tendermint/tendermint@v0.34.13/consensus/state.go:782\nfailed to execute message; message index: 28: timeout packet verification failed: packet timeout has not been reached for height or timestamp: packet timeout",
      "info": "",
      "gas_wanted": "3000000",
      "gas_used": "1026936",
      "events": [],
      "codespace": "channel"
    },

Version

master

Steps to Reproduce

I run a script that sends packets with 60 sec timeout stamp every 1 sec on two chains with 10 and 3 sec block times respectively. Wait for 100 sec and start hermes.

Acceptance Criteria

Don't send timeout packets for packets that have not timed out relatively to the header on the destination chain used for proof root.

---

For Admin Use

• Not duplicate issue
• Appropriate labels applied
• Appropriate milestone (priority) applied
• Appropriate contributors tagged
• Contributor assigned/self-assigned

[ancazamfir]

Problem is that we use Utc::now() instead of the timestamp of header at dst_chain_height (L1211):
https://github.com/informalsystems/ibc-rs/blob/a3b17271781ea4f73a3a64486adada4834b1ba65/relayer/src/link/relay_path.rs#L1200-L1216
The timestamp of the header at height dst_chain_height (or full header) should be obtained once (e.g. when we clear packets) and passed from the caller, or stored in self (??) so we don't query a header from chain for every timeout as this is an expensive operation.