Skip to content
This repository has been archived by the owner on Aug 2, 2022. It is now read-only.

1.5.0-rc1 with state_history_plugin gets stuck on kylin network #6377

Closed
matthewdarwin opened this issue Nov 22, 2018 · 61 comments
Closed

1.5.0-rc1 with state_history_plugin gets stuck on kylin network #6377

matthewdarwin opened this issue Nov 22, 2018 · 61 comments
Assignees
Labels

Comments

@matthewdarwin
Copy link

So I replay the kylin blocks from scratch using config:

/opt/eosio/bin/nodeos --hard-replay --replay-blockchain --disable-replay-opts
plugin = eosio::state_history_plugin
state-history-dir = "state-history"
trace-history = true
chain-state-history = true
state-history-endpoint = 0.0.0.0:9090
[and a few other options that have been there for a long time]

sometime after block 19406900 (not sure exact number), the software goes an infinite loop:

Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.654 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missing trace for transaction 6139bd32da0c523116efcbb2e8536787f68e2b9da364e40792598ea7e64f5815
Nov 22 15:37:56 peer1 nodeos[28294]: {"id":"6139bd32da0c523116efcbb2e8536787f68e2b9da364e40792598ea7e64f5815"}
Nov 22 15:37:56 peer1 nodeos[28294]: thread-0 state_history_plugin.cpp:385 store_traces
Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.659 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missed a block in trace_history.log
Nov 22 15:37:56 peer1 nodeos[28294]: {"name":"trace_history"}
Nov 22 15:37:56 peer1 nodeos[28294]: thread-0 state_history_log.hpp:84 write_entry
Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.661 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missed a block in trace_history.log
Nov 22 15:37:56 peer1 nodeos[28294]: {"name":"trace_history"}
Nov 22 15:37:56 peer1 nodeos[28294]: thread-0 state_history_log.hpp:84 write_entry
Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.662 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missed a block in trace_history.log
Nov 22 15:37:56 peer1 nodeos[28294]: {"name":"trace_history"}
Nov 22 15:37:56 peer1 nodeos[28294]: thread-0 state_history_log.hpp:84 write_entry
Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.669 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missed a block in trace_history.log
Nov 22 15:37:56 peer1 nodeos[28294]: {"name":"trace_history"}
Nov 22 15:37:56 peer1 nodeos[28294]: thread-0 state_history_log.hpp:84 write_entry
Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.670 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missed a block in trace_history.log
Nov 22 15:37:56 peer1 nodeos[28294]: {"name":"trace_history"}
Nov 22 15:37:56 peer1 nodeos[28294]: thread-0 state_history_log.hpp:84 write_entry
Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.678 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missed a block in trace_history.log
Nov 22 15:37:56 peer1 nodeos[28294]: {"name":"trace_history"}
Nov 22 15:37:56 peer1 nodeos[28294]: thread-0 state_history_log.hpp:84 write_entry
Nov 22 15:37:56 peer1 nodeos[28294]: warn 2018-11-22T15:37:56.681 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 22 15:37:56 peer1 nodeos[28294]: missed a block in trace_history.log
etc...

@matthewdarwin
Copy link
Author

I reproduced this issue 3 times. The 2nd and 3rd time I synced to the network just in case replay was the issue. All 3 times, the issue starts with the same transaction: 6139bd32da0c523116efcbb2e8536787f68e2b9da364e40792598ea7e64f5815

Nov 24 05:14:20 testserver2 nodeos[1058]: info 2018-11-24T05:14:20.975 thread-0 producer_plugin.cpp:341 on_incoming_block ] Received block f33b817e6ba2063e... #19408000 @ 2018-11-07T06:06:04.500 signed by eosargentina [trxs:
0, lib: 19407666, conf: 0, latency: 1465696475 ms]
Nov 24 05:14:22 testserver2 nodeos[1058]: warn 2018-11-24T05:14:22.003 thread-0 controller.cpp:246 emit ] signal handler threw exception
Nov 24 05:14:22 testserver2 nodeos[1058]: warn 2018-11-24T05:14:22.004 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
Nov 24 05:14:22 testserver2 nodeos[1058]: missing trace for transaction 6139bd32da0c523116efcbb2e8536787f68e2b9da364e40792598ea7e64f5815
Nov 24 05:14:22 testserver2 nodeos[1058]: {"id":"6139bd32da0c523116efcbb2e8536787f68e2b9da364e40792598ea7e64f5815"}
Nov 24 05:14:22 testserver2 nodeos[1058]: thread-0 state_history_plugin.cpp:385 store_traces

@tbfleming tbfleming self-assigned this Nov 26, 2018
@tbfleming tbfleming added bug and removed Support labels Nov 26, 2018
@tbfleming
Copy link
Contributor

I got it to this point, but am not hitting this issue.

  • Are you using bnet?
  • Which other plugins have you enabled, if any?
  • Have you added any external plugins?

@tbfleming
Copy link
Contributor

  • Did you update submodules when switching to this tag?

@matthewdarwin
Copy link
Author

I have attached my config.ini and Dockerfiles. I am building from the branch.

config.ini.txt
Dockerfile.eosio.txt
Dockerfile.builder.txt

@tbfleming
Copy link
Contributor

Which branch? release/1.5.x?

@matthewdarwin
Copy link
Author

yes, release/1.5.x

@tbfleming
Copy link
Contributor

Still unable to reproduce with Ubuntu Server 18.04. Here's the build steps I used from a fresh VM image (not Docker):

sudo apt install build-essential cmake git
sudo add-apt-repository universe
git clone -b release/1.5.x --recursive git@github.com:EOSIO/eos.git
cd eos
CPU_CORE=20 ./eosio_build.sh

@zreyn
Copy link
Contributor

zreyn commented Nov 27, 2018

I can't reproduce the environment exactly, since I don't have access to the base image (image.eosn.io/eosnation/builder:1.3). The builder image it references is our standard builder: https://github.com/EOSIO/eos/blob/master/Docker/builder/Dockerfile. Using that image with release/1.5.x, I wasn't able to reproduce this.

@matthewdarwin
Copy link
Author

I will do some more testing to figure out exactly what is the issue here... I will report back when I have something to share.

@matthewdarwin
Copy link
Author

I'm testing rc2 and still seeing the same behaviour. next I will test with no docker... (I've tested replaying blocks.log and sync from network, no difference)

@matthewdarwin
Copy link
Author

I have sometimes seen this right before the error messages start:
controller.cpp:246 emit ] signal handler threw exception

@tbfleming
Copy link
Contributor

There’s been a couple reports of this happening on mainnet.

@matthewdarwin
Copy link
Author

matthewdarwin commented Dec 2, 2018

Running this:

sudo apt install build-essential cmake git
sudo add-apt-repository universe
git clone -b release/1.5.x --recursive git@github.com:EOSIO/eos.git
cd eos
CPU_CORE=20 ./eosio_build.sh

generates the following error on ubuntu 18.10:

[ 60%] Building CXX object tools/lli/ChildTarget/CMakeFiles/lli-child-target.dir/ChildTarget.cpp.o
In file included from /tmp/llvm-compiler/llvm/tools/lli/lli.cpp:30:
/tmp/llvm-compiler/llvm/include/llvm/ExecutionEngine/Orc/OrcRemoteTargetClient.h: In member function ‘llvm::Expected<std::vector<char> > llvm::orc::remote::OrcRemoteTargetClient<ChannelT>::readMem(char*, llvm::JITTargetAddress, uint64_t)’:
/tmp/llvm-compiler/llvm/include/llvm/ExecutionEngine/Orc/OrcRemoteTargetClient.h:696:26: error: could not convert ‘((llvm::orc::remote::OrcRemoteTargetClient<ChannelT>*)this)->callB<llvm::orc::remote::OrcRemoteTargetRPCAPI::ReadMem>(Src, Size)’ from ‘Expected<vector<unsigned char,allocator<unsigned char>>>’ to ‘Expected<vector<char,allocator<char>>>’
     return callB<ReadMem>(Src, Size);
            ~~~~~~~~~~~~~~^~~~~~~~~~~

@tbfleming
Copy link
Contributor

That’s #6337 . You need to cd into the /tmp/... folder where it’s building llvm, apply the fix, make -j, then make -j install. After that rerun eosio_build.sh

@matthewdarwin
Copy link
Author

Is this related to #6495

@tbfleming
Copy link
Contributor

Different initial cause. Once the plugin detects a problem it won't continue; this is to prevent it from recording an incorrect history.

@matthewdarwin
Copy link
Author

matthewdarwin commented Jan 4, 2019

From Telegram: EOS Mainnet BPs, jem writes:

I'm doing a state_history replay, and start seeing this about 31.7M block:

warn 2019-01-04T11:34:28.546 thread-0 controller.cpp:244 emit ] 3110000 plugin_exception: Plugin exception
missed a block in chain_state_history.log
{"name":"chain_state_history"}
thread-0 state_history_log.hpp:84 write_entry
31700900 of 34756775

Any clue what happened, or how to mitigate?

I am replaying from a block.log file saved from a peer node, all irreversible blocks in the chain. There are no active peers during replay.

@tbfleming
Copy link
Contributor

The "missed a block" check stops it from creating holes in the data after an initial failure. There should be an earlier error in the log.

@tbfleming
Copy link
Contributor

31.7M block

That sounds like #6495

@matthewdarwin
Copy link
Author

jem added:

I was using mainnet-1.5.1, and had the problem from the block referenced in the issue. Now running v1.6.0-rc2, replay started from a snapshot at block #31685000, and it pushed through that block without complaint.

@jgiszczak
Copy link
Contributor

Did 1.6.0-rc2 work on both mainnet and Kylin?

@matthewdarwin
Copy link
Author

I believe jem got 1.6.0-rc2 to work on mainnet. (Well he started with something older and then upgraded when it got stuck).

I have no luck on kylin still... (I didn't try mainnet and not planning to until I can get all the test networks to work reliably)

of 29430486#015 19387700 of 29430486#015 19387800 of 29430486#015 19387900 of 29430486#015 19388000 of 29430486#015 19388100 of 29430486#015 19388200 of 29430486#015 19388300 of 29430486#015 1
9388400 of 29430486#015 19388500 of 29430486#015 19388600 of 29430486#015 19388700 of 294304
Jan 11 15:25:59 test1 nodeos[90]: warn 2019-01-11T20:25:59.160 thread-0 controller.cpp:235 emit ] 3110000 plugin_exception: Plugin exception
Jan 11 15:25:59 test1 nodeos[90]: missing trace for transaction 6139bd32da0c523116efcbb2e8536787f68e2b9da364e40792598ea7e64f5815
Jan 11 15:25:59 test1 nodeos[90]: {"id":"6139bd32da0c523116efcbb2e8536787f68e2b9da364e40792598ea7e64f5815"}
Jan 11 15:25:59 test1 nodeos[90]: thread-0 state_history_plugin.cpp:385 store_traces
Jan 11 15:25:59 test1 nodeos[90]: warn 2019-01-11T20:25:59.163 thread-0 controller.cpp:235 emit ] 3110000 plugin_exception: Plugin exception
Jan 11 15:25:59 test1 nodeos[90]: missed a block in trace_history.log
Jan 11 15:25:59 test1 nodeos[90]: {"name":"trace_history"}
Jan 11 15:25:59 test1 nodeos[90]: thread-0 state_history_log.hpp:84 write_entry
Jan 11 15:25:59 test1 nodeos[90]: warn 2019-01-11T20:25:59.164 thread-0 controller.cpp:235 emit ] 3110000 plugin_exception: Plugin exception
Jan 11 15:25:59 test1 nodeos[90]: missed a block in trace_history.log

@ramtej
Copy link

ramtej commented Jan 17, 2019

Same issue here:

1.6.0-rc2/EOS Mainnet/ubuntu 18.04:

<4>warn 2019-01-17T21:46:57.013 thread-0 controller.cpp:235 emit ] 3110000 plugin_exception: Plugin exception
missed a block in trace_history.log
{"name":"trace_history"}
thread-0 state_history_log.hpp:84 write_entry
<4>warn 2019-01-17T21:46:57.036 thread-0 controller.cpp:235 emit ] 3110000 plugin_exception: Plugin exception
missed a block in trace_history.log
{"name":"trace_history"}
thread-0 state_history_log.hpp:84 write_entry
<4>warn 2019-01-17T21:46:57.058 thread-0 controller.cpp:235 emit ] 3110000 plugin_exception: Plugin exception
missed a block in trace_history.log
{"name":"trace_history"}
thread-0 state_history_log.hpp:84 write_entry

@tbfleming
Copy link
Contributor

@ramtej The "missed a block" check stops it from creating holes in the data after an initial failure. There should be an earlier error in the log.

@k26dr
Copy link

k26dr commented Jan 28, 2019

so do we have to replay from the start if we get this error? I got this on 1.5.x on Ubuntu 18.04 around block 30M somewhere. I'm upgrading to 1.6.x, can I re-use the existing data on that sync?

@tbfleming
Copy link
Contributor

@k26dr: it sounds like you hit #6496. If you have a backup before that block, then you can restore from that backup.

@matthewdarwin
Copy link
Author

I'm always happy to see there are more victims of this issue, so it is not only me running into the problem.

@eosusa
Copy link

eosusa commented Mar 20, 2019

I'm always happy to see there are more victims of this issue, so it is not only me running into the problem.

I'm starting to think you are the one causing them... Every time I bang my head on something, you already have a github issue open on it... 👍

@tbfleming
Copy link
Contributor

@eosusa what are the specs on your machine or VM?

@eosusa
Copy link

eosusa commented Mar 20, 2019

not impressive for our jungle node :)

4 cores, 8gb ram, 500gb (8 sata raid6)

I can throw some additional specs at it if you think it's resource related

@tbfleming
Copy link
Contributor

I never test below 32gb ram, so that opens a new possibility. Try bumping the ram way up. If that's it then it's possible something somewhere may be swallowing a bad_alloc.

@matthewdarwin
Copy link
Author

I tend to test on 'poor' hardware as well. It's expensive to run a lot of beefy cloud servers just to do testing.
Production servers have much better hardware of course. If things work on poor hardware, then I know when production gets load, it will be handled well.

@jackami
Copy link

jackami commented Mar 21, 2019

@k26dr thanks for your reply. but I used v1.6 and found the same problem. I analyzed the code and found that the write failed because of several abnormal transactions. I modified the code of the eos, and now everything works fine, and the abnormal transaction is filtered out.

missing trace for transaction 3c761209f4e57990dcfc133a3fbc6552241cc153ba85abe1864cfa87f06977c2
missing trace for transaction 7e94f00816d54c8ebde36b1311098c1e07f4ba4588566537b5b432b15b472fc9
missing trace for transaction 7cbcc0da70e0849e5bffbd776307a0898cd6b2c2287de0f1127c38f8b0f37a4f
missing trace for transaction c7d2340b4eb05b3688161b0f9fa1974205afa7f512ca2eae007c26f86bc048b5
missing trace for transaction 8ca98b727ed3d7c21471552e3d1d356101b289f8921259ee2a6568c5c25c37ea
missing trace for transaction 364e4bad8a29b37fd105815ca274f95979d5e10f44efe012c5c16869658aed57
missing trace for transaction 1393a1958a7961f1ea83bdd7b874b82e17315d4f2b8e4d0a4354a949f60243f6
missing trace for transaction 5141ffaa356884f783d7f7ad2158ff2c218b68e1387b68eabca9c6cce7517364
missing trace for transaction 81b1200b49159577aecec19d165a0e1620fa995033a72e3fb5f8a58c9a0aad35
missing trace for transaction 83bfb631f71b5e97819cdfda71f8ebc8af86076289cb89588344d855f64d73f1
missing trace for transaction 8f21f48cc17c9b2a107e34a3aede288edd57062fb644a07d190b0d81a2583d95
missing trace for transaction 0ca2e238d0c532a68eb15cd803dbed6d5ed9ff9408fdeb871c2f5e911c248f2f
missing trace for transaction 1c445657c0586466abd092219989c55a1df36481b06de8ac692d17700e660131
missing trace for transaction 1b37981ddaede2d25aa3a724d5ab5e223a430202e5900a36c430c71e657c5c79
missing trace for transaction f264f7631f48f48f50445056339cf8349eb9a85d54a6358e5acc2ef5e350ebfc
missing trace for transaction 450d8612ac3fa88aa6571d08780e45715791ee330b5655721ece8dc2980545b6
missing trace for transaction d9037338f96e760fe29f21887650b2d98489e8d6df4f9aa3760a7f059bb97650
missing trace for transaction 669001c237938adaadc1155fc075f9dbf299206bbf4adc4f9b51493e9f452e57
missing trace for transaction 4f5d47885a1b9bbe89526f3895cbdc43533eea92e7a7d28bfa3b603aec836fac
missing trace for transaction ed8f6deb13d87be5d2c42000600b1932df7182ece29a838199855e17c55dc641

@eosusa
Copy link

eosusa commented Mar 21, 2019

Bumped it to 12 cores & 22GB RAM... anything more than that will have to wait on some Hyperion indexing to finish to steal some from it sometime tomorrow. Dumped logs/state/statehist and kicked off -delete-all-blocks --genesis-json --disable-replay-opts and will see how it goes!

@eosusa
Copy link

eosusa commented Mar 21, 2019

No dice... was running along smoothly and then seems to have hit the exact same range of blocks and tanked. Getting missing trace transactions again:

info 2019-03-21T11:21:51.205 thread-0 producer_plugin.cpp:345 on_incoming_block ] Received block ef93a26ecf8ec81a... #8856000 @ 2019-01-15T10:05:46.500 signed by eosphereiobp [trxs: 0, lib: 8855668, conf: 0, latency: 5620564705 ms]
warn 2019-03-21T11:21:52.153 thread-0 controller.cpp:236 emit ] signal handler threw exception
warn 2019-03-21T11:21:52.207 thread-0 controller.cpp:234 emit ] 3110000 plugin_exception: Plugin exception
missing trace for transaction d50019cd3ad011b5fca52db59ad671024d70ddb7989de309bc690f8adb2c7a7a
{"id":"d50019cd3ad011b5fca52db59ad671024d70ddb7989de309bc690f8adb2c7a7a"}
thread-0 state_history_plugin.cpp:385 store_traces
warn 2019-03-21T11:21:52.213 thread-0 controller.cpp:234 emit ] 3110000 plugin_exception: Plugin exception
missed a block in trace_history.log

I can give it more resources if needed, but seems odd to be the same place in the chain with 3x memory :)

@tbfleming
Copy link
Contributor

I created a branch off of 1.7.0 to test the bad_alloc idea. Could you try running with it? Look for this message:

bad alloc: Noooooooooo

@tbfleming
Copy link
Contributor

I forgot to give the branch name: test-sh-badalloc

@eosusa
Copy link

eosusa commented Mar 22, 2019

Still no dice:

info 2019-03-21T16:56:18.557 thread-0 main.cpp:99 main ] nodeos version v1.7.0-1-gef64fe27a
...

info 2019-03-22T01:18:37.483 thread-0 producer_plugin.cpp:345 on_incoming_block ] Received block a844f129c27f525d... #8855000 @ 2019-01-15T09:57:00.000 signed by eosdacserval [trxs: 0, lib: 8854676, conf: 227, latency: 5671297483 ms]
info 2019-03-22T01:18:40.564 thread-0 producer_plugin.cpp:345 on_incoming_block ] Received block ef93a26ecf8ec81a... #8856000 @ 2019-01-15T10:05:46.500 signed by eosphereiobp [trxs: 0, lib: 8855668, conf: 0, latency: 5670774064 ms]
warn 2019-03-22T01:18:41.355 thread-0 controller.cpp:238 emit ] signal handler threw exception
warn 2019-03-22T01:18:41.355 thread-0 controller.cpp:234 emit ] 3110000 plugin_exception: Plugin exception
missing trace for transaction d50019cd3ad011b5fca52db59ad671024d70ddb7989de309bc690f8adb2c7a7a
{"id":"d50019cd3ad011b5fca52db59ad671024d70ddb7989de309bc690f8adb2c7a7a"}
thread-0 state_history_plugin.cpp:385 store_traces
warn 2019-03-22T01:18:41.360 thread-0 controller.cpp:234 emit ] 3110000 plugin_exception: Plugin exception
missed a block in trace_history.log
{"name":"trace_history"}
thread-0 state_history_log.hpp:84 write_entry
warn 2019-03-22T01:18:41.363 thread-0 controller.cpp:234 emit ] 3110000 plugin_exception: Plugin exception
missed a block in trace_history.log

Exact same place as last time

@eosusa
Copy link

eosusa commented Mar 22, 2019

So anything else you want me to try or should I roll back to 1.6.3 and see if it's any happier?

@tbfleming
Copy link
Contributor

@arhag has an idea for test code for you to try. We'll try to get it ready for you to test Mon.

@tbfleming
Copy link
Contributor

@eosusa I just pushed more logging to the test-sh-badalloc branch. Please try again; hopefully this may indicate what's happening.

@eosusa
Copy link

eosusa commented Mar 28, 2019

Same crash, much more info in the logs:

info 2019-03-28T02:54:17.889 thread-0 producer_plugin.cpp:345 on_incoming_block ] Received block ef93a26ecf8ec81a... #8856000 @ 2019-01-15T10:05:46.500 signed by eosphereiobp [trxs: 0, lib: 8855668, conf: 0, latency: 6194911389 ms]
warn 2019-03-28T02:54:18.625 thread-0 controller.cpp:238 emit ] boost::exception: /opt/EOSIO/eos/libraries/chainbase/include/chainbase/chainbase.hpp(218): Throw in function const value_type &chainbase::generic_index<boost::multi_index::multi_index_container<eosio::account_control_history_object, boost::multi_index::indexed_by<boost::multi_index::ordered_unique<boost::multi_index::tag<eosio::by_id, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::multi_index::member<eosio::account_control_history_object, chainbase::oideosio::account_control_history_object, &eosio::account_control_history_object::id>, mpl_::na>, boost::multi_index::ordered_unique<boost::multi_index::tag<eosio::by_controlling, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::multi_index::composite_key<eosio::account_control_history_object, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlling_account>, boost::multi_index::member<eosio::account_control_history_object, chainbase::oideosio::account_control_history_object, &eosio::account_control_history_object::id>, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type>, mpl_::na>, boost::multi_index::ordered_unique<boost::multi_index::tag<eosio::by_controlled_authority, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::multi_index::composite_key<eosio::account_control_history_object, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlled_account>, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlled_permission>, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlling_account>, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type>, mpl_::na>, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::interprocess::allocator<eosio::account_control_history_object, boost::interprocess::segment_manager<char, boost::interprocess::rbtree_best_fit<boost::interprocess::mutex_family, boost::interprocess::offset_ptr<void, long, unsigned long, 0>, 0>, iset_index> > > >::emplace(Constructor &&) [MultiIndexType = boost::multi_index::multi_index_container<eosio::account_control_history_object, boost::multi_index::indexed_by<boost::multi_index::ordered_unique<boost::multi_index::tag<eosio::by_id, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::multi_index::member<eosio::account_control_history_object, chainbase::oideosio::account_control_history_object, &eosio::account_control_history_object::id>, mpl_::na>, boost::multi_index::ordered_unique<boost::multi_index::tag<eosio::by_controlling, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::multi_index::composite_key<eosio::account_control_history_object, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlling_account>, boost::multi_index::member<eosio::account_control_history_object, chainbase::oideosio::account_control_history_object, &eosio::account_control_history_object::id>, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type>, mpl_::na>, boost::multi_index::ordered_unique<boost::multi_index::tag<eosio::by_controlled_authority, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::multi_index::composite_key<eosio::account_control_history_object, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlled_account>, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlled_permission>, boost::multi_index::member<eosio::account_control_history_object, eosio::chain::name, &eosio::account_control_history_object::controlling_account>, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type, boost::tuples::null_type>, mpl_::na>, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na, mpl_::na>, boost::interprocess::allocator<eosio::account_control_history_object, boost::interprocess::segment_manager<char, boost::interprocess::rbtree_best_fit<boost::interprocess::mutex_family, boost::interprocess::offset_ptr<void, long, unsigned long, 0>, 0>, iset_index> > >, Constructor = (lambda at /opt/EOSIO/eos/plugins/history_plugin/history_plugin.cpp:116:52)]
Dynamic exception type: boost::exception_detail::clone_impl<boost::exception_detail::error_info_injectorstd::logic_error >
std::exception::what: could not insert object, most likely a uniqueness constraint was violated

warn 2019-03-28T02:54:18.625 thread-0 controller.cpp:234 emit ] fc::exception: 3110000 plugin_exception: Plugin exception
missing trace for transaction d50019cd3ad011b5fca52db59ad671024d70ddb7989de309bc690f8adb2c7a7a
{"id":"d50019cd3ad011b5fca52db59ad671024d70ddb7989de309bc690f8adb2c7a7a"}
thread-0 state_history_plugin.cpp:385 store_traces
warn 2019-03-28T02:54:18.628 thread-0 controller.cpp:234 emit ] fc::exception: 3110000 plugin_exception: Plugin exception
missed a block in trace_history.log

@tbfleming
Copy link
Contributor

(lambda at /opt/EOSIO/eos/plugins/history_plugin/history_plugin.cpp:116:52)

Bingo! That's the cause:

  • history_plugin messed up, halting notification to state_history_plugin
  • the exception was swallowed, hiding the root cause
  • state_history_plugin can't continue since it missed a critical event

@tbfleming
Copy link
Contributor

Reason I could never reproduce: I don't run history_plugin while testing state_history_plugin.

@matthewdarwin
Copy link
Author

So I believe the conclusion is that the following 2 options are not compatible with each other:

plugin = eosio::history_api_plugin
plugin = eosio::state_history_plugin

nodeos should fail to start if both plugins are enabled.

@hamza-kakar
Copy link

i am just using state_history_plugin, not history_api_plugin, still i face the issue.

image

@tbfleming
Copy link
Contributor

@hamza-kakar there should be a first error which triggered that

@matthewdarwin
Copy link
Author

Today I ran across someone else running history and state_history on the same nodeos instance. I referred them to this issue and advised against it.

It would be great to make nodeos fatally stop when both plugins are loaded.

@aclark-b1
Copy link

Created a new issue that outlines the fix proposed by @matthewdarwin
#9176

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests