Osmosis tx fee calculation issues

[mircea-c]

Summary of Bug

Hermes is unable to submit transactions to Osmosis chain because it seems it's miscalculating the TX fee.

Version

v1.0.0-rc.0

Steps to Reproduce

Example transaction using Hermes v1.0.0-rc.0

2022-07-18T19:28:02.580161Z DEBUG ThreadId(113) packet_cmd{src_chain=sifchain-1 src_port=transfer src_channel=channel-17 dst_chain=osmosis-1}:relay{odata=1ec69338 ->Destination @1-7761202; len=1}: prepending Destination client update at height 1-7761203
2022-07-18T19:28:02.678901Z DEBUG ThreadId(113) packet_cmd{src_chain=sifchain-1 src_port=transfer src_channel=channel-17 dst_chain=osmosis-1}:relay{odata=1ec69338 ->Destination @1-7761202; len=1}: [sifchain-1 -> osmosis-1:07-tendermint-1484] MsgUpdateAnyClient from trusted height 1-7761179 to target height 1-7761203
2022-07-18T19:28:02.679292Z  INFO ThreadId(113) packet_cmd{src_chain=sifchain-1 src_port=transfer src_channel=channel-17 dst_chain=osmosis-1}:relay{odata=1ec69338 ->Destination @1-7761202; len=1}: assembled batch of 2 message(s)
2022-07-18T19:28:02.681116Z DEBUG ThreadId(46) send_tx_check{id=1ec69338}:send_tx_with_account_sequence_retry{id=osmosis-1}: sending 2 messages using account sequence AccountSequence(140283)
2022-07-18T19:28:02.681151Z DEBUG ThreadId(46) send_tx_check{id=1ec69338}:send_tx_with_account_sequence_retry{id=osmosis-1}: max fee, for use in tx simulation: Fee { amount: "501uosmo", gas_limit: 5000000 }
2022-07-18T19:28:02.685150Z  WARN ThreadId(46) send_tx_check{id=1ec69338}:send_tx_with_account_sequence_retry{id=osmosis-1}:estimate_gas: failed to simulate tx, falling back on default gas because the error is potentially recoverable: gRPC call failed with status: status: Unknown, message: "account sequence mismatch, expected 140282, got 140283: incorrect account sequence", details: [], metadata: MetadataMap { headers: {"content-type": "application/grpc", "x-cosmos-block-height": "5211900"} }
2022-07-18T19:28:02.685211Z DEBUG ThreadId(46) send_tx_check{id=1ec69338}:send_tx_with_account_sequence_retry{id=osmosis-1}: send_tx: using 5000000 gas, fee Fee { amount: "501uosmo", gas_limit: 5000000 } id=osmosis-1
2022-07-18T19:28:02.692076Z ERROR ThreadId(46) send_tx_check{id=1ec69338}:send_tx_with_account_sequence_retry{id=osmosis-1}: broadcast_tx_sync: Response { code: Err(13), data: Data([]), log: Log("insufficient fees; got: 501uosmo which converts to 501uosmo. required: 12500uosmo: insufficient fee"), hash: transaction::Hash(259D60DE5960CA6CF6E954415A4C9B7B25F0CD3EF6E9FE783CEC5F7BC7561D82) }: diagnostic: the price configuration for this chain may be too low! please check the `gas_price.price` Hermes config.toml
2022-07-18T19:28:02.692181Z  INFO ThreadId(113) packet_cmd{src_chain=sifchain-1 src_port=transfer src_channel=channel-17 dst_chain=osmosis-1}:relay{odata=1ec69338 ->Destination @1-7761202; len=1}: [Async~>osmosis-1] response(s): 1; Err(13):259D60DE5960CA6CF6E954415A4C9B7B25F0CD3EF6E9FE783CEC5F7BC7561D82

Example transaction using the same configuration, same node and Hermes v0.15.0

 send_tx_check{id=b72bfa52}:send_tx_with_account_sequence_retry{id=osmosis-1}: sending 2 messages using account sequence AccountSequence(826907)
 2022-07-18T20:29:42.884750Z DEBUG ThreadId(47) send_tx_check{id=b72bfa52}:send_tx_with_account_sequence_retry{id=osmosis-1}: max fee, for use in tx simulation: Fee { amount: "5001uosmo", gas_limit: 5000000 }
 2022-07-18T20:29:42.919334Z DEBUG ThreadId(47) send_tx_check{id=b72bfa52}:send_tx_with_account_sequence_retry{id=osmosis-1}:estimate_gas: tx simulation successful, gas amount used: 544069
 2022-07-18T20:29:42.919524Z DEBUG ThreadId(47) send_tx_check{id=b72bfa52}:send_tx_with_account_sequence_retry{id=osmosis-1}: send_tx: using 544069 gas, fee Fee { amount: "599uosmo", gas_limit: 598476 } id=osmosis-1
 2022-07-18T20:29:43.029626Z DEBUG ThreadId(47) send_tx_check{id=b72bfa52}:send_tx_with_account_sequence_retry{id=osmosis-1}: broadcast_tx_sync: Response { code: Ok, data: Data([]), log: Log("[]"), hash: transaction::Hash(F0BF4288E9606CB3E0EBEAE84558174DA97AB312C2197F9B4730A3112CC246A1) }
 2022-07-18T20:29:43.034148Z  INFO ThreadId(49) packet_cmd{src_chain=cosmoshub-4 src_port=transfer src_channel=channel-141 dst_chain=osmosis-1}:relay{odata=b72bfa52 ->Destination @4-11315480; len=1}: [Async~>osmosis-1
] response(s): 1; Ok:F0BF4288E9606CB3E0EBEAE84558174DA97AB312C2197F9B4730A3112CC246A1

 2022-07-18T20:29:43.035027Z  INFO ThreadId(49) packet_cmd{src_chain=cosmoshub-4 src_port=transfer src_channel=channel-141 dst_chain=osmosis-1}:relay{odata=b72bfa52 ->Destination @4-11315480; len=1}: success

Acceptance Criteria

Hermes is able to submit transactions to the Osmosis chain

---

For Admin Use

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

[soareschen]

I only see error messages in the first log. The message says:

diagnostic: the price configuration for this chain may be too low! please check the `gas_price.price` Hermes config.toml

Have you tried adjusting the gas config?

The error message also says:

failed to simulate tx, falling back on default gas because the error is potentially recoverable

So this might be an issue with the default gas config.

I also added integration test for Osmosis at #2430. It appears that you need at to set gas_multiplier to at least 1.1 for Osmosis transactions to pass.

[ancazamfir]

@mircea-c can you paste the hermes config for osmosis?

[mircea-c]

@soareschen only the first log is an issue. The second log is an example of the same node and same configuration without gas_multiplier successfully submitting a tx using Hermes v0.15.0

This is the config I used for Hermes v1.0.0

[[chains]]
id = 'osmosis-1'
rpc_addr = 'http://10.10.10.100:26610'
grpc_addr = 'http://10.10.10.100:26612'
websocket_addr = 'ws://10.10.10.100:26610/websocket'
rpc_timeout = '8s'
account_prefix = 'osmo'
key_name = 'aw4'
store_prefix = 'ibc'
memo_prefix = 'Connect the Interchain. Stake with Cephalopod 🐙'
gas_price = { price = 0.0001, denom = 'uosmo' }
gas_multiplier = 1.1
max_gas = 5000000
max_msg_num = 15
max_tx_size = 450000
clock_drift = '7200s'
trusting_period = '10days'
trust_threshold = { numerator = '1', denominator = '3' }
packet_filter = { policy = 'allow', list = [['transfer', 'channel-47']]}

[ancazamfir]

and for v0.15? was the diff only gas_multiplier = 1.1 vs gas_adjustment = 0.1

[ancazamfir]

i think max_gas * price is not enough to get a reasonable fee when simulation fails.
v1.0.0-rc0:
max fee, for use in tx simulation: Fee { amount: "501uosmo", gas_limit: 5000000 }
v0.15.0:
max fee, for use in tx simulation: Fee { amount: "5001uosmo", gas_limit: 5000000 }

have you changed the price?

[mircea-c]

I never used gas_adjustment. Everything is identical except the gas_multiplier = 1.1

[ancazamfir]

I think the fee used when simulation fails is too low. Maybe it was before although I don't understand the difference in the max fee logs if the only change is the gas_multiplier = 1.1.

With the v1.0.0-rc0 you run into simulation failure due to acc sequence mismatch (got > expected). In v0.15.0 we were not recovering from that and therefore the failure due to default fee was not as noticeable.
Note the change that triggers the use of the default fee is https://github.com/informalsystems/ibc-rs/issues/2249.

[adizere]

Had a look also, here are some findings:

1. There is an inconsistency between the two logs with respect to max_fee.

In the failed case, we have

max fee, for use in tx simulation: Fee { amount: "501uosmo", gas_limit: 5000000 }

In the succesful case, we have

max fee, for use in tx simulation: Fee { amount: "5001uosmo", gas_limit: 5000000 }

The gas_limit value is identical across the two logs, but the amount is 10x larger in the second log. (I now understand what it meant that "fee used when simulation fails is too low"). The amount is computed from gas_limit * gas_price.

So either:

• a. we have a bug in how we compute Fee amount in v1.0.0-rc.0 or
• b. different gas_price configurations are being used in the two executions above.

Everything is identical except the gas_multiplier = 1.1

@mircea-c can you please double-check & confirm that indeed the two executions used the same gas_price value? If this is a bug in Hermes is quite subtle and important, thank you!

2. We have an undocumented dependency in config.toml: the value of max_gas is used as default_gas in case the latter is not configured in config.toml.
   Will start a PR for a quick fix.

[mircea-c]

@adizere seems I pasted the wrong log. I was trying different gas values while I was trying to troubleshoot. Here's another log sample from hermes 0.15.0 using the same gas_price value.

 2022-07-17T04:46:57.610652Z DEBUG ThreadId(46) send_tx_check{id=352f3d2b}:send_tx_with_account_sequence_retry{id=osmosis-1}: sending 2 messages using account sequence AccountSequence(140167)
 2022-07-17T04:46:57.610682Z DEBUG ThreadId(46) send_tx_check{id=352f3d2b}:send_tx_with_account_sequence_retry{id=osmosis-1}: max fee, for use in tx simulation: Fee { amount: "501uosmo", gas_limit: 5000000 }
 2022-07-17T04:46:57.631075Z DEBUG ThreadId(46) send_tx_check{id=352f3d2b}:send_tx_with_account_sequence_retry{id=osmosis-1}:estimate_gas: tx simulation successful, gas amount used: 386128
 2022-07-17T04:46:57.631151Z DEBUG ThreadId(46) send_tx_check{id=352f3d2b}:send_tx_with_account_sequence_retry{id=osmosis-1}: send_tx: using 386128 gas, fee Fee { amount: "43uosmo", gas_limit: 424741 } id=osmosis-1
 2022-07-17T04:46:57.651812Z DEBUG ThreadId(46) send_tx_check{id=352f3d2b}:send_tx_with_account_sequence_retry{id=osmosis-1}: broadcast_tx_sync: Response { code: Ok, data: Data([]), log: Log("[]"), hash: transaction::Hash(8525EEBF78EDE50A294949C0632307754F8D4F792850A9C262D198FEB4D5EF5D) }
 2022-07-17T04:46:57.652048Z  INFO ThreadId(110) packet_cmd{src_chain=sifchain-1 src_port=transfer src_channel=channel-17 dst_chain=osmosis-1}:relay{odata=352f3d2b ->Destination @1-7738227; len=1}: [Async~>osmosis-1] response(s): 1; Ok:8525EEBF78EDE50A294949C0632307754F8D4F792850A9C262D198FEB4D5EF5D

[mircea-c]

For more context, here's the full log from a run of v1.0.0-rc.0 just now.

prod0-hermes_osmosis0.log

[ancazamfir]

@mircea found that there is an osmosis configuration parameter min-gas-price-for-high-gas-tx = ".0025" that causes a different/ higher gas price for Tx-es with high gas.
The configured max_gas in hermes (used in the absence of an explict default_gas) causes the Tx that tries to use the max_gas to have insufficient fees.

Details:

• there are two osmosis app.toml params: minimum-gas-prices and min-gas-price-for-high-gas-tx
• there is one hermes config.toml param: gas_price.price
• we recommend that hermes gas_price to be the same as minimum-gas-prices but this is not enough with osmosis high gas Tx fee.
• the min-gas-price-for-high-gas-tx price is used by the osmosis node for Tx-es with gas >= 1M and this threshold doesn't seem to be configurable
• when the Tx gas is above the threshold then the max(minimum-gas-prices, min-gas-price-for-high-gas-tx) is used

A few possible solutions we should explore:

• configure same values for min-gas-... in app.toml, e.g min-gas-price-for-high-gas-tx = 0.0001.
• to cover the cases where account sequence mismatch with got > expected, when hermes uses default_gas, make sure default_gas has a value smaller strict than the 1M threshold. Note the gas_multiplier does not apply when we fall back to default_gas, therefore a value of 999999 should be good enough.

There is a more general case where a Tx includes many IBC messages, up to max_msg_num (as configured in hermes' config.toml).

• as seen in @mircea's logs, for packet relaying, the UpdateClient + RecvPacket combo consumes most gas.
  • Tx-es with one UdateClient and two RecvPacketuse around 650k gas, one with a singleRecvPacket` around 550k gas.

It is possible and likely that hermes will build a Tx with gas that exceeds the threshold and simulation will fail for this Tx and retries/ clearing will not solve this I believe.

Some solutions:

• observe the chain and make sure the Tx gas threshold is not passed by adjusting max_msg_num < 5 (??)
• add a new configuration param to hermes gas_price = { price = 0.0001, high_gas_tx_price = 0.025, denom = 'stake' }.
  • Not sure about this as the whole rationale for different/ higher gas price for big Tx-es is to discourage their submission and hermes as a mempool user should do the same.

Other notes from the log:

• looks like in some cases the gas_multiplier = 1.1 is not enough, search for Err(11):

 2022-07-21T13:01:57.513423Z ERROR ThreadId(47) send_tx_check{id=2def95ac}:send_tx_with_account_sequence_retry{id=osmosis-1}: broadcast_tx_sync: Response { code: Err(11), data: Data([]), log: Log("out of gas in location: ReadFlat; gasWanted: 501784, gasUsed: 502624: out of gas"), hash: transaction::Hash(5E215472104939210C2E2A0E30B565AE19C2B78A1811D8F9EE729B2368233EC2) } : diagnostic: the gas requirement is higher than the configured maximum gas! please check the Hermes config.toml
...

• the hermes diagnostic in the log above is wrong and should be corrected

[ancazamfir]

Based on the above I think these hermes config changes should help short term:

max_gas = 999999
gas_multiplier = 1.2
max_msg_num = 5

[mircea-c]

OK. I'll start an instance of Hermes with those changes and will report back.

[ancazamfir]

Due to https://github.com/informalsystems/ibc-rs/issues/2477 I suggest using an even smaller max_gas until that is fixed. Maybe max_gas = 800000.