Exceeding CPU limit when pushing eosio.system contract

[krotkiewicz]

Hey,
when I run custom testnet nodeos with custom genesis file, I randomly get below error when pushing eosio.system contract.

$ cleos set contract eosio /tmp/eosio.contracts/build/contracts/eosio.system/
Reading WASM from /tmp/eosio.contracts/build/contracts/eosio.system/eosio.system.wasm...
Publishing contract...
error 2019-12-07T13:03:09.462 nodeos    http_plugin.cpp:652           handle_exception     ] FC Exception encountered while processing chain.push_transaction
Error 3080004: Transaction exceeded the current CPU usage limit imposed on the transaction

I use eos 1.8.5 from eostudio/eos:v1.8.5 docker image and eosio.contracts from release/1.8.x branch plus following genesis and config files:

{
  "initial_timestamp": "2018-03-02T12:00:00.000",
  "initial_key": "EOS55oVd4ZyC2QMiAMzs1WFYzEYU1GKAAALPCa45Dzs9wrUWo3hjD",
  "initial_configuration": {
    "max_block_net_usage": 1048576,
    "target_block_net_usage_pct": 1000,
    "max_transaction_net_usage": 524288,
    "base_per_transaction_net_usage": 12,
    "net_usage_leeway": 500,
    "context_free_discount_net_usage_num": 20,
    "context_free_discount_net_usage_den": 100,
    "max_block_cpu_usage": 100000,
    "target_block_cpu_usage_pct": 500,
    "max_transaction_cpu_usage": 50000,
    "min_transaction_cpu_usage": 100,
    "max_transaction_lifetime": 3600,
    "deferred_trx_expiration_window": 600,
    "max_transaction_delay": 3888000,
    "max_inline_action_size": 4096,
    "max_inline_action_depth": 4,
    "max_authority_depth": 6
  }
}

chain-state-db-size-mb = 65536
reversible-blocks-db-size-mb = 65536

producer-name = eosio
http-server-address = 0.0.0.0:8888

plugin = eosio::chain_api_plugin
plugin = eosio::history_plugin
plugin = eosio::history_api_plugin
plugin = eosio::http_plugin
plugin = eosio::producer_plugin
plugin = eosio::producer_api_plugin

access-control-allow-origin = *
http-validate-host = false
enable-stale-production = true
max-transaction-time = 3000000

filter-on = *

To easily reproduce it I prepared a repo with Dockerfile: https://github.com/ulamlabs/eos-regtest.
Just build the image and run it couple of times.

What I tried?

Increasing max CPU time in genesis file - then the pushing the system contract takes seconds and errors with Please increase the expiration time of your transaction!.

Thanks for helping.

[jgiszczak]

The max-transaction-time of 3000000 ms you have specified exceeds the maximum block time of 500 ms. No transaction taking that long can be incorporated into a block. You could try increasing max_transaction_cpu_usage in genesis.json from 50000 microseconds to something less than 500000 microseconds.

[krotkiewicz]

@jgiszczak I already tried that. When I increase all max cpus in the genesis file to some absurd values (like minutes), the transaction takes forever to execute and the node gives up with timeout error.

So there is something bad going on when executing that transaction (put system contract), looks like a deadlock to me.

[jgiszczak]

As I said, increasing those limits to beyond the block time is useless. Any transaction taking longer than block time will fail with the timeout you are seeing, always. The transaction is expiring in the queue after repeated failures to be incorporated into a block.

Try building the 1.8.3 release of the system contract rather than the 1.8.x branch. What version of CDT did you use to build the system contract?

[jgiszczak]

Testing demonstrates that changing max_transaction_cpu_usage in genesis.json still works as advertised. Note that EOS Mainnet uses a value of 150000 microseconds. It's safe to say 50000 is too low for current common contracts.

[ksiazkowicz]

I can confirm that changing those values works, but the issue that we're facing is that no matter if we set these values to something unreasonable like 20 seconds per block or we use mainnet values (0.2s for max block CPU usage and 0.15s for max transaction CPU usage), it doesn't guarantee us that this transaction won't exceed the deadline. We counteract this by repeatedly submitting it until it succeeds and ultimately it does, usually requiring only about ~0.01-0.03s of CPU time. There must be some reason why this transaction either exceeds 0.15s deadline or gets executed under just a fraction of that time.

We use eosio.cdt 1.6.3 as advised in release notes. Using v1.8.3 of system contract doesn't seem to resolve the issue.

[jgiszczak]

Reopening. I'm getting three independent reports of consistent transaction timing failures in the 1.8 branch, ranging all the way from 1.8.0 all the way up to 1.8.6.

[netuoso]

I am experiencing this same issue when deploying eosio.system contract.

EOS Version: 1.8.9
CDT Version: 1.6.3
Contracts Version: 1.83

Not sure exactly when it appeared but it is preventing local testnet deployment.

[netuoso]

I was able to solve this problem by adding http-max-response-time-ms = 500 to the nodeos config.ini. This option was added with EOS version 1.8.9+

The default value is 30ms which may not be enough on a local, single node testnet

[heifner]

Note tx_cpu_usage_exceeded "Transaction exceeded the current CPU usage limit imposed on the transaction" is different than timeout_exception "deadline ${d} exceeded by ${t}us". timeout_exception is tied to http-max-response-time-ms.

[netuoso]

Correct, the original poster said.

Increasing max CPU time in genesis file - then the pushing the system contract takes seconds and errors with Please increase the expiration time of your transaction!.

So when he fixes the tx_cpu_usage_exceeded bug, he gets a new bug. The new issue will be an expired transaction. I was experiencing the same thing and it was specifically related to deployed the eosio.system contract after a version update.

The newer versions of EOSIO defaulted the http-max-response-time to 30 to prevent RPC node abuse. As you have to use the RPC node to set the contract, the imposed limit caused issues on some hardware in a local testnet. Please at least attempt the above setting in a testnet before declaring it does not fix the described issue.

Hopefully this information helps someone as it seemed to help me running into the same issues. I have seen some form of these errors constantly when making changes that did not include increasing allowed http response time. I suppose it is possible the original commenter was using outdated eosio.contracts that didnt work with his EOS version, but I had this issue with multiple versions of eosio.contracts.

[heifner]

Thanks for the additional info.

[ksiazkowicz]

Thanks @netuoso. I tried your solution but it doesn't seem to make much impact for me. I'm using eosio 1.8.9, eosio.cdt 1.6.3 and eosio.contracts 1.8.3. I've set http-max-response-time-ms to 1000, max_transaction_cpu_usage to 150000 and max_block_cpu_usage to 200000. While some runs are successful, others get stuck trying to deploy eosio.system contract.

Here is the output from docker logs eosio 2>&1 | grep "eosio.system" -A 5:

+ retry cleos set contract eosio /tmp/eosio.contracts/build/contracts/eosio.system/
+ cleos set contract eosio /tmp/eosio.contracts/build/contracts/eosio.system/
Reading WASM from /tmp/eosio.contracts/build/contracts/eosio.system/eosio.system.wasm...
Publishing contract...
error 2020-01-24T09:08:54.344 nodeos    http_plugin.cpp:694           handle_exception     ] FC Exception encountered while processing chain.push_transaction
Error 3080006: Transaction took too long
Error Details:
deadline exceeded
--
+ cleos set contract eosio /tmp/eosio.contracts/build/contracts/eosio.system/
Reading WASM from /tmp/eosio.contracts/build/contracts/eosio.system/eosio.system.wasm...
Publishing contract...
info  2020-01-24T09:09:04.501 nodeos    producer_plugin.cpp:1920      produce_block        ] Produced block 0000002d151a542a... #45 @ 2020-01-24T09:09:04.500 signed by eosio [trxs: 0, lib: 44, confirmed: 0]
error 2020-01-24T09:09:04.609 nodeos    http_plugin.cpp:694           handle_exception     ] FC Exception encountered while processing chain.push_transaction
Error 3080006: Transaction took too long
Error Details:
--
+ cleos set contract eosio /tmp/eosio.contracts/build/contracts/eosio.system/
Reading WASM from /tmp/eosio.contracts/build/contracts/eosio.system/eosio.system.wasm...
Publishing contract...
error 2020-01-24T09:09:14.834 nodeos    http_plugin.cpp:694           handle_exception     ] FC Exception encountered while processing chain.push_transaction
Error 3080006: Transaction took too long
Error Details:
deadline exceeded
--
+ cleos set contract eosio /tmp/eosio.contracts/build/contracts/eosio.system/
Reading WASM from /tmp/eosio.contracts/build/contracts/eosio.system/eosio.system.wasm...
Publishing contract...
info  2020-01-24T09:09:25.001 nodeos    producer_plugin.cpp:1920      produce_block        ] Produced block 000000562aade7a7... #86 @ 2020-01-24T09:09:25.000 signed by eosio [trxs: 0, lib: 85, confirmed: 0]
error 2020-01-24T09:09:25.091 nodeos    http_plugin.cpp:694           handle_exception     ] FC Exception encountered while processing chain.push_transaction
Error 3080006: Transaction took too long
Error Details:
--
+ cleos set contract eosio /tmp/eosio.contracts/build/contracts/eosio.system/
Reading WASM from /tmp/eosio.contracts/build/contracts/eosio.system/eosio.system.wasm...
Publishing contract...
error 2020-01-24T09:09:35.350 nodeos    http_plugin.cpp:694           handle_exception     ] FC Exception encountered while processing chain.push_transaction
Error 3080006: Transaction took too long
Error Details:
deadline exceeded

[netuoso]

Apologies, it helped me for deploying a few times but now I am re-encountering the issue.

Update: I am using an underpowered laptop and running the testnet in a docker instance via docker-compose. After some digging, it seems the issue I was experiencing with deadline exceeded while deploying the eosio.system contract was related to hardware constraints, not a software config error.

I was able to make my machine immediately start working by increasing the available RAM to the docker process as well as setting a CPU niceness of -18. https://en.wikipedia.org/wiki/Nice_(Unix)

TL:DR; if you are experiencing this issue, try to upgrade your hardware or ensure your virtual process has sufficient resources to deploy the contract within the timespan of a single block.