State history plugin

[tbfleming]

Change Description

The state history plugin gives external processes a way to track chain state (tables), transaction history, and blocks. External processes could store this data into a database (e.g. https://github.com/EOSIO/fill-postgresql ), transform the data to meet app needs (e.g. a https://github.com/EOSIO/demux-js action handler), or index the data and provide an end-user api (e.g. a /v1/history replacement).

The plugin stores:

• Chain DB table changes (per block) (enable with --chain-state-history)
• Transaction traces (per block) (enable with --trace-history)

The plugin allows clients to fetch via block index:

• Blocks from the block log
• Chain DB table changes (per block) (enable with --chain-state-history)
• Transaction traces (per block) (enable with --trace-history)

The plugin stores its data in files which can move between machines. BPs could provide these files along with snapshots, reducing the need for new nodes to replay.

The plugin provides a streaming websocket interface. To reduce the load on nodeos, the interface uses a serialized binary format instead of JSON and the plugin does minimal processing to handle requests. However, since this interface provides a high data volume and has no abuse mitigations, we don't recommend publicly exposing its port.

[cc32d9]

I just noticed, the options like chain-state-history are not implemented as config file options, but only available from CLI arguments. Is it on purpose?

[cc32d9]

I don't expect shared memory from 1.4.x to work.

well it works, kind of. Nodeos is processing blocks, but at a strangely slow pace.

[tbfleming]

config file arguments: sounds like a bug.

ubuntu 18.10: I just got stuck on this:

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]

Whoops. I forgot to switch branches. Trying ubuntu build again.

[cc32d9]

uh oh. It was that slow with the options in config.ini:

plugin = eosio::state_history_plugin
trace-history = true
chain-state-history = true

and command line:

/usr/local/eosio/bin/nodeos --data-dir /home/eosio/data --config-dir /home/eosio/etc --disable-replay-opts

Now, I removed those lines from config.ini, and the command line is

/usr/local/eosio/bin/nodeos --data-dir /home/eosio/data --config-dir /home/eosio/etc --disable-replay-opts --chain-state-history --trace-history

Now it is running fast and as expected.

[cc32d9]

but the log says " thread-0 history_log.hpp:80 write_entry" but the state-history directory contents aren't changing. lsof shows the state history files are open, but strace doesn't show any write operationsn into them.

Something is totally weird going on. I'll do a clean build, maybe there were some leftovers from merging.

[cc32d9]

cleaned andn rebuilt, the same effect. Nodeos is not updating files in state-history. Then I stopped nodeos, deleted state-history directory, and started nodeos. Now it's slow, and updating the state history files. So it went into some state that made it think it was writing, but it was not, and after deleting the history files, it went back to actually writing. Looks like a bug in history_log.hpp.

[cc32d9]

But it's only updating the trace history, but not the state history:

eosio@sthist:~$ ls -al data/state-history/
total 521
drwxr-xr-x 2 eosio eosio      6 Nov 17 18:35 .
drwxr-xr-x 6 eosio eosio      6 Nov 17 18:35 ..
-rw-r--r-- 1 eosio eosio      0 Nov 17 18:35 chain_state_history.index
-rw-r--r-- 1 eosio eosio      0 Nov 17 18:35 chain_state_history.log
-rw-r--r-- 1 eosio eosio    296 Nov 17 18:39 trace_history.index
-rw-r--r-- 1 eosio eosio 531888 Nov 17 18:39 trace_history.log

[tbfleming]

@cc32d9 are you getting logs like this? If so I reproduced it:

info  2018-11-17T18:57:33.188 thread-0  state_history_plugin.c:412    store_chain_state    ] Placing initial state in block 27282718
warn  2018-11-17T18:57:43.999 thread-0  controller.cpp:244            emit                 ] 10 assert_exception: Assert Exception
value.size() <= MAX_NUM_ARRAY_ELEMENTS:
    {}
    thread-0  raw.hpp:559 pack
info  2018-11-17T18:57:44.134 thread-0  state_history_plugin.c:412    store_chain_state    ] Placing initial state in block 27282719
warn  2018-11-17T18:57:53.654 thread-0  controller.cpp:244            emit                 ] 10 assert_exception: Assert Exception
value.size() <= MAX_NUM_ARRAY_ELEMENTS:
    {}
    thread-0  raw.hpp:559 pack
info  2018-11-17T18:57:53.733 thread-0  state_history_plugin.c:412    store_chain_state    ] Placing initial state in block 27282720
warn  2018-11-17T18:58:03.263 thread-0  controller.cpp:244            emit                 ] 10 assert_exception: Assert Exception
value.size() <= MAX_NUM_ARRAY_ELEMENTS:
    {}
    thread-0  raw.hpp:559 pack
info  2018-11-17T18:58:03.461 thread-0  state_history_plugin.c:412    store_chain_state    ] Placing initial state in block 27282721

[tbfleming]

This patch to libraries/fc/include/fc/io/raw_fwd.hpp works around the above:

@@ -11,7 +11,7 @@
 #include <unordered_map>
 #include <set>

-#define MAX_NUM_ARRAY_ELEMENTS (1024*1024)
+#define MAX_NUM_ARRAY_ELEMENTS (1024*1024*1024)
 #define MAX_SIZE_OF_BYTE_ARRAYS (20*1024*1024)

 namespace fc {

[tbfleming]

Here's ubuntu 18.10 starting from a snapshot from OSX. I had to apply the patch above:

todd@todd-ubuntu-1810:~/from-snap$ ~/eos/build/programs/nodeos/nodeos -l ~/logging.json -d ./data --config-dir ./config --abi-serializer-max-time-ms 99999999 --chain-state-db-size-mb 102400 --plugin eosio::state_history_plugin --trace-history --chain-state-history --p2p-listen-endpoint 0.0.0.0:9802 --state-history-endpoint 0.0.0.0:8082 --http-server-address 127.0.0.1:8882 --disable-replay-opts   --plugin eosio::http_plugin --http-validate-host 0 --access-control-allow-origin "*" --plugin eosio::chain_api_plugin --p2p-peer-address publicnode.cypherglass.com:9876 --snapshot data/snapshots/snapshot-01a04d18dfd98b21906dab2badb4b41e13a010e2897a895601056f0a995023ba.bin
info  2018-11-17T18:50:47.742 thread-0  chain_plugin.cpp:333          plugin_initialize    ] initializing chain plugin
info  2018-11-17T18:50:47.752 thread-0  state_history_plugin.c:544    plugin_initialize    ] ip_port: 0.0.0.0:8082 host: 0.0.0.0 port: 8082
info  2018-11-17T18:50:47.752 thread-0  history_log.hpp:200           open_log             ] trace_history.log is empty
info  2018-11-17T18:50:47.752 thread-0  history_log.hpp:200           open_log             ] chain_state_history.log is empty
info  2018-11-17T18:50:47.752 thread-0  http_plugin.cpp:422           plugin_initialize    ] configured http to listen on 127.0.0.1:8882
info  2018-11-17T18:50:47.752 thread-0  net_plugin.cpp:2898           plugin_initialize    ] Initialize net plugin
info  2018-11-17T18:50:47.752 thread-0  net_plugin.cpp:2924           plugin_initialize    ] host: 0.0.0.0 port: 9802
info  2018-11-17T18:50:47.752 thread-0  net_plugin.cpp:2995           plugin_initialize    ] my node_id is 493d1e94435d134b9e69b19b3674e86c4a3f0ba4192cb3a6692d2ac52f901cf2
info  2018-11-17T18:50:47.752 thread-0  http_plugin.cpp:377           operator()           ] configured http with Access-Control-Allow-Origin: *
info  2018-11-17T18:50:47.753 thread-0  main.cpp:111                  main                 ] nodeos version v1.4.3-209-g7313140d6-dirty
info  2018-11-17T18:50:47.753 thread-0  main.cpp:112                  main                 ] eosio root is /home/todd/.local/share
info  2018-11-17T18:50:47.753 thread-0  main.cpp:113                  main                 ] nodeos using configuration file /home/todd/from-snap/config/config.ini
info  2018-11-17T18:50:47.753 thread-0  main.cpp:114                  main                 ] nodeos data directory is /home/todd/from-snap/./data
error 2018-11-17T18:50:47.753 thread-0  controller.cpp:1664           startup              ] No head block in fork db, perhaps we need to replay
info  2018-11-17T18:51:30.684 thread-0  controller.cpp:404            init                 ] database initialized with hash: 4d7daef223aee2749fee393dc91f15dc461fff3394fb233b066b6fd88db72163
info  2018-11-17T18:51:30.684 thread-0  chain_plugin.cpp:722          plugin_startup       ] starting chain in read/write mode
info  2018-11-17T18:51:30.684 thread-0  chain_plugin.cpp:726          plugin_startup       ] Blockchain started; head block is #27282712, genesis timestamp is 2018-06-08T08:08:08.888
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:486           plugin_startup       ] start listening for http requests
info  2018-11-17T18:51:30.684 thread-0  chain_api_plugin.cpp:77       plugin_startup       ] starting chain_api_plugin
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/abi_bin_to_json
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/abi_json_to_bin
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_abi
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_account
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_block
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_block_header_state
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_code
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_code_hash
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_currency_balance
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_currency_stats
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_info
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_producer_schedule
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_producers
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_raw_abi
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_raw_code_and_abi
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_required_keys
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_scheduled_transactions
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_table_by_scope
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_table_rows
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/get_transaction_id
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/push_block
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/push_transaction
info  2018-11-17T18:51:30.684 thread-0  http_plugin.cpp:554           add_handler          ] add api url: /v1/chain/push_transactions
info  2018-11-17T18:51:30.684 thread-0  net_plugin.cpp:3014           plugin_startup       ] starting listener, max clients is 25
warn  2018-11-17T18:51:30.684 thread-0  net_plugin.cpp:707            connection           ] created connection to publicnode.cypherglass.com:9876
info  2018-11-17T18:51:30.684 thread-0  net_plugin.cpp:1921           connect              ] host: publicnode.cypherglass.com port: 9876
info  2018-11-17T18:51:30.684 thread-0  producer_plugin.cpp:718       plugin_startup       ] producer plugin:  plugin_startup() begin
info  2018-11-17T18:51:30.684 thread-0  producer_plugin.cpp:752       plugin_startup       ] producer plugin:  plugin_startup() end
warn  2018-11-17T18:51:30.886 thread-0  transaction_context.cp:108    deadline_timer       ] Using polled checktime; deadline timer too inaccurate: min:2us max:10515us mean:2916us stddev:3645us
info  2018-11-17T18:51:31.065 thread-0  state_history_plugin.c:412    store_chain_state    ] Placing initial state in block 27282713
info  2018-11-17T18:52:01.970 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 05bda9df4ffc7f4e... #27283000 @ 2018-11-16T18:40:25.500 signed by jedaaaaaaaaa [trxs: 36, lib: 27282712, conf: 0, latency: 87096470 ms]
info  2018-11-17T18:52:31.473 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 85b861e81a499597... #27284000 @ 2018-11-16T18:48:46.500 signed by eosswedenorg [trxs: 26, lib: 27283666, conf: 0, latency: 86624973 ms]
info  2018-11-17T18:52:59.927 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block ba363c10e5cafa8b... #27285000 @ 2018-11-16T18:57:06.500 signed by eosswedenorg [trxs: 17, lib: 27284674, conf: 0, latency: 86153427 ms]
info  2018-11-17T18:53:30.290 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 6d9fa9f4b4ad98fa... #27286000 @ 2018-11-16T19:05:28.000 signed by eosriobrazil [trxs: 27, lib: 27285670, conf: 0, latency: 85682290 ms]
info  2018-11-17T18:54:00.147 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 26fad2e61954f612... #27287000 @ 2018-11-16T19:13:48.000 signed by eosriobrazil [trxs: 25, lib: 27286675, conf: 240, latency: 85212147 ms]
info  2018-11-17T18:54:30.580 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 3fa7a65f1ecf7dde... #27288000 @ 2018-11-16T19:22:09.500 signed by eosnewyorkio [trxs: 30, lib: 27287668, conf: 0, latency: 84741080 ms]
info  2018-11-17T18:55:00.799 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 3357b8c38c354bf0... #27289000 @ 2018-11-16T19:30:30.000 signed by eosnewyorkio [trxs: 25, lib: 27288676, conf: 240, latency: 84270799 ms]
info  2018-11-17T18:55:32.415 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 4829baf497ba12de... #27290000 @ 2018-11-16T19:38:50.500 signed by eosliquideos [trxs: 26, lib: 27289670, conf: 0, latency: 83801915 ms]
info  2018-11-17T18:56:03.887 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 6a9ef01c4a31b3bd... #27291000 @ 2018-11-16T19:47:10.500 signed by eoslaomaocom [trxs: 25, lib: 27290666, conf: 0, latency: 83333387 ms]
info  2018-11-17T18:56:33.719 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block a6f4f322f0e6b662... #27292000 @ 2018-11-16T19:55:30.500 signed by eoslaomaocom [trxs: 29, lib: 27291674, conf: 0, latency: 82863219 ms]
info  2018-11-17T18:57:05.623 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block beec2ebf97312865... #27293000 @ 2018-11-16T20:03:53.500 signed by eosiosg11111 [trxs: 5, lib: 27292656, conf: 0, latency: 82392123 ms]
info  2018-11-17T18:57:38.486 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block eb9b7c4277aebf27... #27294000 @ 2018-11-16T20:12:14.000 signed by eosiosg11111 [trxs: 24, lib: 27293671, conf: 0, latency: 81924486 ms]
info  2018-11-17T18:58:10.663 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block f3637f0e7b9e9fc5... #27295000 @ 2018-11-16T20:20:34.000 signed by eoshuobipool [trxs: 36, lib: 27294667, conf: 0, latency: 81456663 ms]
info  2018-11-17T18:58:43.349 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block f852a59b28d244de... #27296000 @ 2018-11-16T20:28:54.000 signed by eoshuobipool [trxs: 28, lib: 27295675, conf: 240, latency: 80989349 ms]
info  2018-11-17T18:59:15.962 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block df215cab37f6ceec... #27297000 @ 2018-11-16T20:37:14.000 signed by eosflytomars [trxs: 30, lib: 27296671, conf: 0, latency: 80521962 ms]
info  2018-11-17T18:59:45.920 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block aee4015404999c8e... #27298000 @ 2018-11-16T20:45:34.500 signed by eosfishrocks [trxs: 40, lib: 27297667, conf: 0, latency: 80051421 ms]
info  2018-11-17T19:00:15.867 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 0b2e57a4c6afd2f5... #27299000 @ 2018-11-16T20:53:54.500 signed by eosfishrocks [trxs: 30, lib: 27298674, conf: 0, latency: 79581367 ms]
info  2018-11-17T19:00:47.837 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block 0ec931ab31111e1e... #27300000 @ 2018-11-16T21:02:15.500 signed by eosdacserver [trxs: 38, lib: 27299669, conf: 0, latency: 79112337 ms]
info  2018-11-17T19:01:17.730 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block ce027e49d00ff954... #27301000 @ 2018-11-16T21:10:36.500 signed by eosdacserver [trxs: 20, lib: 27300674, conf: 0, latency: 78641230 ms]
info  2018-11-17T19:01:45.390 thread-0  producer_plugin.cpp:341       on_incoming_block    ] Received block dec9b57f46c88617... #27302000 @ 2018-11-16T21:18:56.500 signed by eoscannonchn [trxs: 29, lib: 27301670, conf: 0, latency: 78168890 ms]

[cc32d9]

yes, I see the same messages with value.size() <= MAX_NUM_ARRAY_ELEMENTS

[cc32d9]

cool, with this fix it's running fast as it's supposed to, and updating both log files

[cc32d9]

Interestingly, nodeos with the state history plugin takes only about 3% more CPU time than the bare one. Still I think it will be better with LZ4, or maybe even more good, is to support different compression options, and also no compression