Metamask-extension: etimateGas failing 9/10 times when it should succeed

[callmenick]

In MM, we're frequently seeing the error:

Transaction Error. Exception thrown in contract code.

I know for sure that the tx should succeed, because I have sufficient funds, and the tx is a legal one. I'm seeing the message spawning from here:

https://github.com/MetaMask/metamask-extension/blob/b046378e335f23b7c2447c2ad40fe4d8ab2da67a/ui/app/components/pending-tx.js#L285

The option simulationFails gets added to txMeta.simulationFails when the simulation fails.

https://github.com/MetaMask/metamask-extension/blob/c0893f2bcc0bf6163265bf75a4afad387169afd1/app/scripts/lib/tx-gas-utils.js#L33

If the gas estimation fails, then it's assumed that the tx will fail...thus the error gets thrown. Implementation of estimateTxGas is here:

https://github.com/MetaMask/metamask-extension/blob/c0893f2bcc0bf6163265bf75a4afad387169afd1/app/scripts/lib/tx-gas-utils.js#L41

This ultimately calls a web3 query for estimateGas after a few checks and balances. It looks like your inner calls to estimateGas are failing majority of times, which I'm guessing relies on the Infura providers. The message

Transaction Error. Exception thrown in contract code.

is also not very accurate, as the contract never actually throws an error. Not sure what's going on under the hood here, maybe you can shed more light?

Funnily enough, we were calling estimateGas right before our contract calls to show users some UI telling them that the tx would fail if estimateGas wasn't in the safe range. This prevented the subsequent send tx, which also prevented the MM dialog from popping up. That started backfiring 24 hours ago, when the estimateGas call was failing 95% of times (even when I was 100% certain it shouldn't fail). People just weren't able to buy at all...the UI was getting blocked, and they thought something was wrong. Since we removed that from our code, MM is absorbing those errors now. If people just reject and retry a bunch of times, eventually it works.

So similar behaviours exhibited whether we call estimateGas or MM does (MM would call it anyway), it's just a matter of where the bug is absorbed. The bug ultimately lies in the fact that estimateGas is returning false information way more often than not.

[kumavis]

@callmenick thanks for the great write up -- now we need reproduction steps

can you capture one of the eth_estimateGas requests from the metamask background network tab?

find the relevant request, right click and select "copy as curl"

[callmenick]

@kumavis no prob. I'll draft up reproduction steps soon.

[callmenick]

Ok, using the CryptoKitties app. I'm going through the steps of purchasing a kitty that's on sale. I have enough eth in my wallet as captured by screenshot, and kitties are listed for sale.

I'm attempting the purchase on Kitty #524668, currently for sale on the app, and verified on sale from reading directly from the contract. This one may not be for sale anymore soon, but it's happening on all kitties. This is what I see:

Here's a full screenshot of the mm network at this moment:

The subsequent requests being made (as inspected in background) that I think are relevant are:

curl 'https://api.infura.io/v1/jsonrpc/mainnet/eth_gasPrice?params=%5B%5D' -H 'Host: api.infura.io' -H 'User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:58.0) Gecko/20100101 Firefox/58.0' -H 'Accept: */*' -H 'Accept-Language: en-US,en;q=0.5' --compressed -H 'origin: moz-extension://45ac8375-e0e2-fa41-8c38-8bd5ef38e835' -H 'Connection: keep-alive'

and

curl 'https://api.infura.io/v1/jsonrpc/mainnet/eth_getBlockByNumber?params=%5B%22latest%22%2Ctrue%5D' -H 'Host: api.infura.io' -H 'User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:58.0) Gecko/20100101 Firefox/58.0' -H 'Accept: */*' -H 'Accept-Language: en-US,en;q=0.5' --compressed -H 'origin: moz-extension://45ac8375-e0e2-fa41-8c38-8bd5ef38e835' -H 'Connection: keep-alive'

The first one looks like the gas call, which I think is the one misbehaving (as the orange error in the mm dialog is about gas). If I reject a bunch of times and try again, eventually the calls succeed and the dialog doesn't display the error.

I'm testing this on firefox, but the exact same behaviour is exhibited on chrome.

[danfinlay]

To understand this problem, it's important to understand the difference between gasPrice and gasLimit.

Gas price is your bid (in ether) per unit of gas, which ticks up with each operation of a smart contract call.

Gas limit is the maximum number of gas ticks you're willing to pay before automatically failing a transaction (to create a maximum transaction fee).

The two transactions you've pointed out are gas price and getting the latest block, neither is related to computing the gas limit.

These errors are related to the result of estimateGas, which estimates the gas limit required to perform an action.

Here is an example call that replicates an error result from infura:

curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":2520615457159,"jsonrpc":"2.0","method":"eth_estimateGas","params":[{"from":"0x96539de51aff4a0c814d788cbf3568ec5023f7ff","to":"0xb1690c08e213a35ed9bab7b318de14420fb57d8c","value":"0x18bae75b0b88b0","data":"0x454a2ab30000000000000000000000000000000000000000000000000000000000080861","gas":"0x73daa2","gasPrice":"0x4a817c800"}]}' --compressed

This method gets the following response from Infura, and presumably from Geth itself:

{"jsonrpc":"2.0","id":2520615457159,"error":{
  "code":-32000,"message":"gas required exceeds allowance or always failing transaction"
}}

We do not cause this error at MetaMask, this is the backend (geth), estimating that the proposed transaction would exceed the allowance (which we set to the previous block gas limit). This means this transaction could not be performed, even if a whole block was dedicated to processing it.

Why could this happen? I'll look at the smart contract for clues, but this is the smart contract developer's responsibility in general.

I notice the first four bytes of the method data is 454a2ab3, and so I look this up on 4byte.directory and find it is the method bid(uint256).

I then visit the recipient contract source code on etherscan and refer to that method's code.

I see no loops in that method that could cause excessive gas usage, so at first glance it's tempting to say "there's no way this is the smart contract's fault", but without a good solidity debugger, I don't think we can actually confidently say that.

To narrow down the issue more, I tried the same action while connected to Parity instead of Geth. Parity threw a similar error:

{"jsonrpc":"2.0","error":{"code":-32015,"message":"Transaction execution error.","data":"Internal(\"Requires higher than upper limit of 80000290\")"},"id":2520615457162}

To me, this looks more and more like a legitimate on-chain out of gas error, not a geth error nor a MetaMask error. Since my cursory read of your smart contract didn't reveal anything that would use this much gas, and neither did yours, I would suggest pursuing the advice of a solidity/EVM expert, who could step through the transaction and maybe find exactly what is using so much gas.

[dete]

Really comprehensive answer, @danfinlay. Life on the frontier can be rough! 😆

[callmenick]

Yup, thanks @danfinlay! We're going to dig in hard today and tomorrow as well. So many moving parts, the root of it can be anywhere at this point. I'm looking into some things we changed a couple weeks ago, which actually coincides with these errors. Could be a weird chain reaction happening...I'll keep you posted.

[gnidan]

Hello! @danfinlay alerted me to this issue since I've been doing some maintenance on trufflesuite/truffle-debugger.

Not sure if this applies, but wanted to give you a heads up that if you are able to get a failing transaction (ie, get past the estimateGas part), then the truffle-debugger in its current state should be able to give some indication what's going wrong.

Note that this is also predicated on a couple things:

• You'll need the CryptoKitties source Truffle project, with code corresponding to what's deployed on mainnet
• You'll need a local geth node, or some RPC node that supports debug_traceTransaction, configured in truffle.js (you'll also need up-to-date artifacts in build/contracts/)

With all three of those, you should be able to do truffle debug <tx> --network mainnet and step through the Solidity source. This should help identify infinite loops that might be causing gas price to exceed the maximum.

Apologies if this is just noise... I suspect the issue described here doesn't offer much room for existing tooling to help. Was curious what progress you may have made investigating this; at the very least I'd love to hear your frustrations in getting to the bottom of it, to help inform future work for Truffle's debugger, and/or to offer additional help if possible.

Thanks!

[flockonus]

Hey guys, thank you very much for the support.

We gave thought for the problem being in the contract, but i believe from the video and curls pasted below it will be easy to see it's not the case, on my point of view, can be either in the integration with Metamask (either our side or the plugin), or Infura req/response.

Following @kumavis we followed the debug directions and have the results attached

VIDEO WITH REPRODUCTION STEPS

1st attempt - says gas limit error!
curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":460980157,"jsonrpc":"2.0","method":"eth_call","params":[{"to":"0x06012c8cf97bead5deae237070f9587f8e7a266d","data":"0x6352211e0000000000000000000000000000000000000000000000000000000000081a58"},"latest"]}' --compressed
curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":9957744432038,"jsonrpc":"2.0","method":"eth_estimateGas","params":[{"from":"0xba52c75764d6f594735dc735be7f1830cdf58ddf","to":"0xb1690c08e213a35ed9bab7b318de14420fb57d8c","value":"0x4229380407bd6a0","data":"0x454a2ab30000000000000000000000000000000000000000000000000000000000081a58","gas":"0x73f79b","gasPrice":"0x4a817c800"}]}' --compressed

... wait long enough ....
curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":460980206,"jsonrpc":"2.0","method":"eth_call","params":[{"to":"0x06012c8cf97bead5deae237070f9587f8e7a266d","data":"0x6352211e0000000000000000000000000000000000000000000000000000000000081a58"},"latest"]}' --compressed
curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":9957744432041,"jsonrpc":"2.0","method":"eth_estimateGas","params":[{"from":"0xba52c75764d6f594735dc735be7f1830cdf58ddf","to":"0xb1690c08e213a35ed9bab7b318de14420fb57d8c","value":"0x4229380407bd6a0","data":"0x454a2ab30000000000000000000000000000000000000000000000000000000000081a58","gas":"0x73f79b","gasPrice":"0x4a817c800"}]}' --compressed

[danfinlay]

@flockonus unfortunately I'm failing to reproduce errors for any of those requests:

➜  ✗ curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":460980157,"jsonrpc":"2.0","method":"eth_call","params":[{"to":"0x06012c8cf97bead5deae237070f9587f8e7a266d","data":"0x6352211e0000000000000000000000000000000000000000000000000000000000081a58"},"latest"]}' --compressed

{"jsonrpc":"2.0","id":460980157,"result":"0x000000000000000000000000b1690c08e213a35ed9bab7b318de14420fb57d8c"}
➜  ✗ curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":9957744432038,"jsonrpc":"2.0","method":"eth_estimateGas","params":[{"from":"0xba52c75764d6f594735dc735be7f1830cdf58ddf","to":"0xb1690c08e213a35ed9bab7b318de14420fb57d8c","value":"0x4229380407bd6a0","data":"0x454a2ab30000000000000000000000000000000000000000000000000000000000081a58","gas":"0x73f79b","gasPrice":"0x4a817c800"}]}' --compressed

{"jsonrpc":"2.0","id":9957744432038,"result":"0x16212"}
➜  ✗ curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":460980206,"jsonrpc":"2.0","method":"eth_call","params":[{"to":"0x06012c8cf97bead5deae237070f9587f8e7a266d","data":"0x6352211e0000000000000000000000000000000000000000000000000000000000081a58"},"latest"]}' --compressed

{"jsonrpc":"2.0","id":460980206,"result":"0x000000000000000000000000b1690c08e213a35ed9bab7b318de14420fb57d8c"}
➜  ✗ curl 'https://api.infura.io/v1/jsonrpc/mainnet' -H 'origin: null' -H 'accept-encoding: gzip, deflate, br' -H 'accept-language: en-US,en;q=0.9' -H 'user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.167 Safari/537.36' -H 'content-type: application/json' -H 'accept: application/json' -H 'authority: api.infura.io' --data-binary '{"id":9957744432041,"jsonrpc":"2.0","method":"eth_estimateGas","params":[{"from":"0xba52c75764d6f594735dc735be7f1830cdf58ddf","to":"0xb1690c08e213a35ed9bab7b318de14420fb57d8c","value":"0x4229380407bd6a0","data":"0x454a2ab30000000000000000000000000000000000000000000000000000000000081a58","gas":"0x73f79b","gasPrice":"0x4a817c800"}]}' --compressed

{"jsonrpc":"2.0","id":9957744432041,"result":"0x16212"}

[callmenick]

@danfinlay @kumavis @gnidan I think we found the solution, and it seems to be an issue that bubbled from some recent change in geth all the way up through to the app. I'll be writing a detailed synopsis here soon, but just want to give you three a ton of thanks for the in depth details and discoveries. They all helped a lot.

[danfinlay]

Looking forward to that synopsis, @callmenick! Can we mark this as closed?

[jamboj]

@danfinlay, I ALWAYS get "gas required exceeds allowance or always failing transaction".

I've tried your both "eth_estimateGas" curls and they fail.

I've also tried these two web3.js and they also always fail:

let gasEstimate = await contract.methods.buy(tokenId).estimateGas({from:myAddress, gas:maxGasPrice}).catch(function(error) { console.log("Err1:", error); });

and

var txPayloadData = contract.methods.buy(tokenId).encodeABI();

var rawTx =
{
            nonce:          myNonce,
            gasLimit:       gasEstimate,
            gasPrice:       gasPrice,
            value:          web3.utils.toWei('2', 'ether'),
            to:             cAddress,
            from:           myAddress,
            chainId:        chainId,
            data:           txPayloadData
}

const signedTx = await account.signTransaction(rawTx);
gasEstimate = await web3.eth.estimateGas({to:cAddress, data:signedTx.rawTransaction}).catch(function(error) { console.log("Err2:", error); });

yield

Err1: Error: Returned error: gas required exceeds allowance or always failing transaction
Err2: Error: Returned error: gas required exceeds allowance or always failing transaction

though the tx is perfectly fine if sent.

Could it be the diff in our setup somewhere? Any other debugging hints?
I use web3.js 1.0.0-beta.30 but it seems the issue is deeper..
I do NOT run a local node - connecting to remote infura ws
thanks guys

[callmenick]

@jamboj is the value of your tx changing (like in a CryptoKitty ascending / descending auction), or is it a fixed value? I'm still to do my write up, but in summary, blockchain time is different to absolute time, and the geth implementation of estimateGas had changed under the hood. This meant that calculating the current auction value for a kitty in relation to absolute time was in conflict with how geth was doing the calculation (using block time).

This wold also explain why when @danfinlay ran the requests we sent him, they did not throw any errors. Because enough time would've passed such that there was a more than reasonable time buffer to account for the discrepancy in block time and absolute time when doing the estimate gas calculation, which ultimately depended on a value the we supplied "some time ago". Note: ascending price auctions would've still failed, understandably so.

[jamboj]

@callmenick, I'm actually testing with a different contract but I've double-checked and I'm pretty sure the px is not the issue. I have enough ETH on my account and the item px is well below tx value. Contract allows overbidding. Also transaction does go through if I send it.

[jamboj]

BTW this is probably not the greatest error message. It should be more explicit on what check actually fails.

[danfinlay]

@jamboj wrote:

I've double-checked and I'm pretty sure the px is not the issue

What's the px? Sounds like your problem is distinct, and deserves its own issue. Please provide a reproduction site for the bug, to help debugging it.

I'm always in favor of better error messages, if you can find a way of providing them, please do. That is worth another issue, it sounds like the CryptoKitties bug has been found.

Great job, @callmenick, looking forward to that writeup!

[jamboj]

Thanks @danfinlay. It is obv not a MetaMask issue but a web3/geth level (and same for error message). I was just hoping to get some insight in the process of you looking into the OP's issue. I've opened a separate post on stackexchange (not sure if external links allowed here)

[danfinlay]

They are. Btw this is probably a great candidate for trying out the new truffle debugger they released today:

https://github.com/trufflesuite/truffle-debugger

[jamboj]

cool thanks for the hint!

[jamboj]

Here's my stackexchange post for reference:
https://ethereum.stackexchange.com/questions/39655/web3-1-0-0-estimategas-always-throws-gas-required-exceeds-allowance-or-always-f